search

Xpra-org / xpra

Persistent remote applications for X11; screen sharing for X11, MacOS and MSWindows.
https://xpra.org/
GNU General Public License v2.0
1.98k stars 169 forks source link

incomplete redraw: black rectangle on right-hand side #252

Closed totaam closed 10 years ago

totaam commented 11 years ago

Issue migrated from trac ticket # 252

component: core | priority: critical | resolution: fixed

2013-02-11 01:38:00: onlyjob created the issue

Some dialogs are rendered incomplete with black rectangle on right-hand side.

The attached screenshot demonstrate the problem on a dialog in gnucash application (enter payment for invoice): [[Image(/raw-attachment/ticket/252/xpra_gnucash-enter-payment.png)]]

I've also seen the described effect in ktorrent when it is just started before session is attached.

Here are the instructions how to reproduce in Iceweasel (aka Firefox): You need "tree style tab" extension activated. In its properties set "Auto hide" --> "For Normal Window Mode" to "Auto Shrink tab bar". Assuming that tab list on the left hand side, when you hover it, it should expand and become wider partially overlapping web page content with transparency effect. Now there is a weird part: if you open a particular web page:

    http://phoronix.com/forums/forum.php

and move mouse cursor over tree-tabs it will expand but the web page will be hidden under big black rectangle until tree tab shrinks itself (when you move the mouse cursor away). I can easily reproduce that in local session (i.e. the bug is manifesting with all encodings) on phoronix.com and few other web sites.

This is not a regression and was present in previous Xpra versions.

totaam commented 11 years ago

2013-02-11 01:39:10: onlyjob uploaded file xpra_gnucash-enter-payment.png (28.2 KiB)

xpra_gnucash-enter-payment.png

totaam commented 11 years ago

2013-02-11 10:47:20: antoine changed status from new to accepted

totaam commented 11 years ago

2013-02-11 10:47:20: antoine changed owner from * to antoine*

totaam commented 11 years ago

2013-02-11 10:47:20: antoine commented

There may be two issues here:

  • we don't handle transparency (#279)
  • the window dimensions don't seem to match the damage we send, maybe the applications in question resize themselves and we should re-send the new damage with the updated dimensions (just a guess at this point)
totaam commented 11 years ago

2013-02-16 23:27:05: onlyjob commented

When incomplete-black-redraw happens in iceweasel server side xpra prints the following to log:

2013-02-17 10:23:19,775 the window <OverrideRedirectWindowModel object at 0x473afa0 (wimpiggy+window+OverrideRedirectWindowModel at 0x2a7c120)> is not composited!?
2013-02-17 10:23:26,260 the window <OverrideRedirectWindowModel object at 0x4748e10 (wimpiggy+window+OverrideRedirectWindowModel at 0x7f4dd02d51a0)> is not composited!?
2013-02-17 10:23:28,308 the window <OverrideRedirectWindowModel object at 0x4748e10 (wimpiggy+window+OverrideRedirectWindowModel at 0x7f4dd02d50a0)> is not composited!?
2013-02-17 10:23:31,785 the window <OverrideRedirectWindowModel object at 0x4748d70 (wimpiggy+window+OverrideRedirectWindowModel at 0x44602e0)> is not composited!?
2013-02-17 10:23:32,815 the window <OverrideRedirectWindowModel object at 0x4748d70 (wimpiggy+window+OverrideRedirectWindowModel at 0x30edd60)> is not composited!?
2013-02-17 10:23:32,815 the window <OverrideRedirectWindowModel object at 0x4748d70 (wimpiggy+window+OverrideRedirectWindowModel at 0x30edd60)> is not composited!?
2013-02-17 10:23:35,455 the window <OverrideRedirectWindowModel object at 0x474c550 (wimpiggy+window+OverrideRedirectWindowModel at 0x30edf20)> is not composited!?
2013-02-17 10:23:35,883 the window <OverrideRedirectWindowModel object at 0x4748dc0 (wimpiggy+window+OverrideRedirectWindowModel at 0x2a7cf00)> is not composited!?
2013-02-17 10:23:35,883 the window <OverrideRedirectWindowModel object at 0x4748dc0 (wimpiggy+window+OverrideRedirectWindowModel at 0x2a7cf00)> is not composited!?
2013-02-17 10:23:37,224 the window <OverrideRedirectWindowModel object at 0x4748e10 (wimpiggy+window+OverrideRedirectWindowModel at 0x7f4dd02d5520)> is not composited!?
2013-02-17 10:23:37,224 the window <OverrideRedirectWindowModel object at 0x4748e10 (wimpiggy+window+OverrideRedirectWindowModel at 0x7f4dd02d5520)> is not composited!?
2013-02-17 10:23:44,350 the window <OverrideRedirectWindowModel object at 0x4748dc0 (wimpiggy+window+OverrideRedirectWindowModel at 0x2a7ce00)> is not composited!?
2013-02-17 10:23:45,269 the window <OverrideRedirectWindowModel object at 0x474c640 (wimpiggy+window+OverrideRedirectWindowModel at 0x4460040)> is not composited!?
2013-02-17 10:23:45,269 the window <OverrideRedirectWindowModel object at 0x474c640 (wimpiggy+window+OverrideRedirectWindowModel at 0x4460040)> is not composited!?
2013-02-17 10:23:47,182 the window <OverrideRedirectWindowModel object at 0x4748dc0 (wimpiggy+window+OverrideRedirectWindowModel at 0x30ede20)> is not composited!?
2013-02-17 10:23:48,884 the window <OverrideRedirectWindowModel object at 0x3195a00 (wimpiggy+window+OverrideRedirectWindowModel at 0x30edb20)> is not composited!?
totaam commented 11 years ago

2013-02-24 16:52:45: antoine commented

Am I the only one seeing this problem: I cannot use the keyboard at all with gnucash! (which is a little bit more worrying than the black borders... which I have not seen yet)

gnucash-2.4.11-2.fc18.x86_64
totaam commented 11 years ago

2013-02-25 07:30:16: onlyjob commented

I'm using gnucash-2.4.11-2 on Debian -- it's all good with keyboard.

What comes to mind is that there could be a modal dialog that you need to dismiss to be able to use the main window, but you probably out-ruled this already...

To reproduce the black-box problem with gnucash you need to "enter payment for invoice". I'll email you a test database.

totaam commented 11 years ago

2013-02-25 07:44:54: onlyjob commented

Instructions to reproduce "black-box" problem in Gnucash:

(Assuming there is a database opened with at least one invoice) Business --> Customer --> Find Invoice, put "*" to search field, click "Find" button twice, choose invoice, click "View / Edit invoice" button (it will open as tab in main window), dismiss find dialog, then (finally) click the right-most button on toolbar (image with stacked coins).

This dialog is always incomplete in Xpra session for me.

totaam commented 11 years ago

2013-03-20 01:31:12: onlyjob commented

As of trunk r3003 I can't reproduce the issue in Firefox / Iceweasel any more (with or without GL). However in gnucash there is no change and some dialogs are still incompletely drawn.

totaam commented 11 years ago

2013-03-21 23:14:33: onlyjob commented

Replying to [comment:6 onlyjob]:

As of trunk r3003 I can't reproduce the issue in Firefox / Iceweasel any more (with or without GL). However in gnucash there is no change and some dialogs are still incompletely drawn.

Correction: the issue was not reproducible with client r3003 and server 0.8.8. Unfortunately I see the same issue with 0.9.0-r3019 on both client and server.

totaam commented 11 years ago

2013-03-22 02:07:45: antoine changed status from accepted to new

totaam commented 11 years ago

2013-03-22 02:10:50: antoine changed owner from antoine to onlyjob

totaam commented 11 years ago

2013-03-22 02:10:50: antoine commented

There is nothing between r3003 and r3019 that has anything to do with drawing, it is all gl and launcher stuff. Could this be a server issue between 0.8.8 and 0.9.0?

Are you sure about your diagnostics? Is it easily reproducible? And if so, can you bisect it?

totaam commented 11 years ago

2013-03-22 02:41:51: onlyjob commented

IMHO it looks like client issue, but I don't have enough expertise to pinpoint the issue.

I can reproduce very easy, it happens all the time for me. I know it's confusing but there was no mistake, for whatever reason the issue temporary disappeared when I connected to session 0.8.8 using client 0.9.0-r3003.

When I started the new session using Xpra-0.9.0-r3019 the issue returned. I don't know how to explain it...

Please advise what can I do to help you track down the issue. This is not a regression and it was like this as long as I remember. I'm not familiar with bisection but I could probably try some older builds although I can't see anything of relevance between r3003 and r3019...

I will report if I find anything...

totaam commented 11 years ago

2013-03-22 02:50:57: antoine commented

Well, if it is easily reproducible, it should only take about 5 minutes to identify the commit: 16 revisions to test exactly, this can be bisected down to the bad commit in 4 steps - without even needing to look at the commit changes to figure out if there were any differences.

Unless... when you say "when I started the new session using Xpra-0.9.0-[r3019](../commit/1169f99890f22487f073eba04d3d4c19a8e3efd3)" you mean that this is a server upgrade? In which case, bisection will take a little bit longer. And you should be able to confirm that this is a server side issue by testing the "bad" server with both 0.8.x and 0.9.0 clients to rule out the client side.

totaam commented 11 years ago

2013-03-22 03:27:16: onlyjob commented

The only combination which worked was client-0.9.0 connected to server-0.8.8 which leaves all revisions in between to test while restart the server every time -- that's a lot... :( I already tried connecting to server r3019 with client-r3003 but the issue didn't go away...

totaam commented 11 years ago

2013-03-22 03:44:45: antoine commented

Right, so this is not a client issue then.

Which leaves anything from 2875 to r3003 on the server, that's 128 revisions exactly (!), and can be bisected down in 8 steps. Note: you don't need to restart the server, and "xpra upgrade" should be enough.

totaam commented 11 years ago

2013-03-22 07:09:56: onlyjob commented

Tried 0.8.8 on server side but couldn't reproduce the desirable effect -- the problem is there. :(
I have no idea what to attribute the accidental and temporary lack of this problem...

However I found something interesting that can probably spread some light on the issue. When Iceweasel window has focus, moving mouse cursor over affected tab demonstrate the issue when main window blackens on tab expansion. But when I open "Session info" window from Xpra menu and hover mouse over affected tab while "session info" has focus, tab expands without blackening, as it should. So somehow "black rectange" happens with active window only...

totaam commented 11 years ago

2013-03-22 07:47:00: antoine commented

Hah, well if it is a focus issue, we have a good candidate for this: try reverting r2910 (see #282) - does this help?

totaam commented 11 years ago

2013-03-22 08:36:04: onlyjob commented

Tried r3036 with r2910 reverted -- looks like there is no difference. The problem still occurs only inside active (iceweasel) window. I can't reproduce if "About Xpra" dialog has focus....

totaam commented 11 years ago

2013-03-22 08:40:17: antoine commented

Just double-checking, you've restarted the server after applying the patch right?

If so, I can only suggest bisecting from there:

  • install a specific revision: 
    svn up -r 2910
./setup.py install
  • figure out if the bug still occurs, then go up or down towards 2875 or towards 3003.. (ie: next revs would be ~2895 or ~2960 depending on which way the bisection goes)
totaam commented 11 years ago

2013-03-22 08:58:46: onlyjob commented

Yes I restarted the server. Actually I tried twice, with "xpra upgrade" and with brand new instance "xpra start" etc. to eliminate possible effect of dummy X11.

I think bisecting exhausted its potential. I tried different revisions but today I couldn't reproduce desirable effect with any of them. I tend to think that when I mistakenly reported success I could have something that stole the focus from iceweasel and therefore prevented the problem. (FYI I remember chatting in pidgin at a time).

totaam commented 11 years ago

2013-03-30 12:16:59: onlyjob commented

I found an application that doesn't work for me at all in Xpra: kcalc. It opens with black window and do not redraw/refresh so it is completely unusable. I reproduced with 0.8.8 and trunk-r3043.

totaam commented 11 years ago

2013-04-21 15:21:28: totaam changed priority from major to critical

totaam commented 11 years ago

2013-04-21 15:21:28: totaam changed status from new to assigned

totaam commented 11 years ago

2013-04-21 15:21:28: totaam changed owner from onlyjob to totaam

totaam commented 11 years ago

2013-04-21 15:21:28: totaam commented

Here is a debug log sample of what kcalc does:

new window 0xa00016L - 10485782
Discovered new ordinary window: \
    <WindowModel object at 0x2e6ca50 (wimpiggy+window+WindowModel at 0x27c4c00)> (geometry=(0, 0, 1, 1))
new_window(new-window, \
    <WindowModel object at 0x2e6ca50 (wimpiggy+window+WindowModel at 0x27c4c00)>, \
    2, 0, 0, 1, 1, \
    ('title', 'pid', 'size-hints', 'class-instance', 'icon', \
     'client-machine', 'transient-for', 'window-type', 'modal'), \
    None)
    metadata={'size-constraints': {'minimum-size': (253, 254), \
     'maximum-size': (0, 0)}, 'window-type': ['_NET_WM_WINDOW_TYPE_NORMAL'], \
     'modal': False, 'title': 'KCalc', 'class-instance': ['kcalc', 'Kcalc'], \
     'client-machine': 'desktop', 'pid': 26362}
WindowModel.composite_configure_event(<CompositeHelper object at 0x2e6cd70 (wimpiggy+composite+CompositeHelper at 0x27c4100)>, \
    <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e6cd20 (GdkWindow at 0x2de5360)>, \
     'send_event': 0, 'height': 1, 'width': 1, \
     'window': <gtk.gdk.Window object at 0x2e6cd20 (GdkWindow at 0x2de5360)>, \
     'y': 0, 'x': 0, 'serial': 2110L, 'border_width': 0, 'type': 22, \
     'display': <gtk.gdk.Display object at 0x2ac3460 (GdkDisplayX11 at 0x2b5d210)>}>)
_process_configure_window([2, 1, 32, 253, 254, {}]) old window geometry: (0, 0, 1, 1)
Ignoring X error: BadValue on <built-in function configureAndNotify>
_do_update_client_geometry: 253x254
_do_update_client_geometry: size=(0, 0, 0, 0)
Uh-oh, our size doesn't fit window sizing constraints: 253x254 vs 0x0
_do_update_client_geometry: position=(1, 32)
Ignoring X error: BadValue on <built-in function configureAndNotify>
(..)

It looks like we're not honouring the minimum-size hints when we first map the window (new_window(..)), instead we use the dimensions we're given by the application (1x1), then we get an X11 error (BadValue) when we try to reconfigure the window to the correct dimensions we get from the client (_process_configure_window), which means that the backing window stays at 1x1 and so does the backing pixmap... and that is why we don't see anything.

totaam commented 11 years ago

2013-04-22 07:58:42: totaam commented

Interestingly, with r3122 + r3123 I get:

_update_client_geometry: owner()=<DesktopManager object at 0x322aa00 (xpra+server+DesktopManager at 0x32834c0)>
_do_update_client_geometry: 1x1
_do_update_client_geometry: hints=WMSizeHints( \
    {'min_size': (253, 254), 'max_aspect_ratio': None, 'win_gravity': 1, \
     'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, \
     'min_aspect': None, 'max_size': (0, 0), 'max_aspect': None \
    })
_do_update_client_geometry: sanitized hints=WMSizeHints( \
    {'min_size': (253, 254), 'max_aspect_ratio': None, 'win_gravity': 1, \
     'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, \
     'min_aspect': None, 'max_size': (0, 0), 'max_aspect': None \
    })
_do_update_client_geometry: size=(0, 0, 0, 0)
_do_update_client_geometry: position=(0, 0)
Ignoring X error: BadValue on <built-in function configureAndNotify>

So the problem comes from the size hints which have max_size=0x0 which makes us resize the window to 0x0, and this is where the BadValue comes from.

Now... why do we get 0x0? Is this allowed, should we ignore it and use min_size which is bigger?

totaam commented 11 years ago

2013-04-22 09:54:31: totaam changed status from assigned to new

totaam commented 11 years ago

2013-04-22 09:54:31: totaam changed owner from totaam to onlyjob

totaam commented 11 years ago

2013-04-22 09:54:31: totaam commented

There is nothing in the XSizeHints documentation that specifies what values are legal for max-size, or what to do when it conflicts with min-size, so r3124 dicards the bogus max-size before we call GDK's gdk_window_constrain_size which was returning the invalid size to us.

Looks fixed to me, at least for kcalc. Please confirm.

totaam commented 11 years ago

2013-04-22 10:37:18: onlyjob commented

Yes r3124 fixed kcalc and it's a big step forward. :)

Unfortunately the original issue is still unchanged: I verified gnucash and iceweasel where black box almost completely hides the main window on some web sites...

totaam commented 11 years ago

2013-04-22 16:30:41: totaam uploaded file gnucash-ok.png (110.3 KiB)

gnucash looking ok gnucash-ok.png

totaam commented 11 years ago

2013-04-22 16:33:05: totaam commented

I can reproduce the "tree style tab" extension issue on [http://phoronix.com/forums/forum.php], I've used Firebug to remove elements from the html page until the black rectangle disappeared. I'm pretty sure that this one is caused by a transparent window overlayed on top of the html page (by the site or the extension - don't know which) and since we don't handle transparency yet (#279), I don't think there's much we can do here (also a different issue from the one that affected kcalc)

The only other remaining issue in this ticket is gnucash, and the dialog displays fine for me following the instructions in comment:5, see screenshot: [[Image(/raw-attachment/ticket/252/gnucash-ok.png)]]

So unless I am missing something (a way to reproduce with gnucash perhaps?), then I am tempted to close this ticket.

totaam commented 11 years ago

2013-04-22 17:00:53: onlyjob commented

Please, pretty please let's try a bit harder with gnucash and firefox issues. We probably are getting closer.

With gnucash I can reliably reproduce and provide "-d all" logs for analysis.(One sample I already sent by email).

In Firefox I don't understand why the issue is not reproducible when "About Xpra" dialog is opened and active. Why black box is only happening in active window??? Perhaps something can be done after all if issue depends on window focus so much.

totaam commented 11 years ago

2013-04-22 17:08:39: totaam commented

No, let's not! At least for the firefox extension issue: even if we were to spend a lot more time on it, chances are we'll just find a way to get the focus to do something different and cause the overlay window to not show up, not actually fixing the real issue which is the lack of transparency support (#279).

New datapoint communicated by email: the window contents exist and are shown with "xpra screenshot", just not when the client maps it. Which is odd.

Maybe dumping:

xpra info

of when the window is complete and of when it isn't could shed some light (checking the window properties and dimensions)

totaam commented 11 years ago

2013-04-22 17:09:31: totaam changed status from new to assigned

totaam commented 11 years ago

2013-04-22 17:09:31: totaam changed owner from onlyjob to totaam

totaam commented 11 years ago

2013-04-22 17:09:31: totaam edited the issue description

totaam commented 11 years ago

2013-04-22 18:46:43: totaam commented

The xpra info did not reveal anything, in both cases (working / non-working) the data was similar, and the dimensions were identical:

window[21].class-instance=['gnucash', 'Gnucash']
window[21].dimensions=[560, 276]
window[21].minimum-size=[560, 276]
window[21].window-type=['_NET_WM_WINDOW_TYPE_DIALOG']

The dimensions match the screenshot once we take the window borders into account.

I just need a better test case, spending 5 minutes each time I try to test to find out that I cannot reproduce the display bug is no way to make progress.

totaam commented 11 years ago

2013-04-22 19:06:36: onlyjob commented

Just to add that somehow it depends on position of dialog. It renders OK if appears in upper-left corner and it is always broken (as on screenshot) when appears in the centre of gnucash main window. It seems random where the dialog will open. Dismissing it and opening again may help to get it appear in another place but sometimes over 20 repetitions may be needed to reproduce. To me broken dialog often appears on first click.

totaam commented 11 years ago

2013-04-22 19:12:26: totaam commented

Which reminds me, the position (and other attributes) are chosen by the client-side window manager, not by the application running on the server. As we don't (yet?) honour all the hints that it may supply (like "legacy" ones: #302)

So:

  • what is your DE?
  • it could be useful to grab the 
    _do_update_client_geometry: ...

    messages from the "-d all" log.

  • xwininfo and xprop output for the dialog (from within xpra)
totaam commented 11 years ago

2013-04-24 03:55:53: onlyjob commented

This is on KDE with Gnucash-2.4.12

I started xpra as follows xpra start :11 -d all --no-speaker --no-microphone --no-system-tray --no-clipboard

then attached: xpra attach :11 --no-mmap --no-speaker

Here is fragment of "-d all" log when I click "Enter payment..." (dialog appeared OK):

2013-04-24 12:32:03,131 process non-ui packet ping
2013-04-24 12:32:03,633 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366770723633
2013-04-24 12:32:03,634 process non-ui packet ping_echo
2013-04-24 12:32:03,634 ping echo client load=(1030, 1620, 1670), measured server latency=1
2013-04-24 12:32:09,566 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366770729565
2013-04-24 12:32:09,567 process non-ui packet ping_echo
2013-04-24 12:32:09,567 ping echo client load=(1030, 1610, 1670), measured server latency=1
2013-04-24 12:32:13,132 process non-ui packet ping
2013-04-24 12:32:13,634 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366770733634
2013-04-24 12:32:13,635 process non-ui packet ping_echo
2013-04-24 12:32:13,635 ping echo client load=(1030, 1600, 1660), measured server latency=1
2013-04-24 12:32:14,318 will process ui packet pointer-position
2013-04-24 12:32:14,319 will process ui packet pointer-position
2013-04-24 12:32:14,322 will process ui packet pointer-position
2013-04-24 12:32:14,323 will process ui packet pointer-position
2013-04-24 12:32:14,325 will process ui packet pointer-position
2013-04-24 12:32:14,327 will process ui packet pointer-position
2013-04-24 12:32:14,329 will process ui packet pointer-position
2013-04-24 12:32:14,331 will process ui packet pointer-position
2013-04-24 12:32:14,333 will process ui packet pointer-position
2013-04-24 12:32:14,335 will process ui packet pointer-position
2013-04-24 12:32:14,338 will process ui packet pointer-position
2013-04-24 12:32:14,342 will process ui packet pointer-position
2013-04-24 12:32:14,344 will process ui packet pointer-position
2013-04-24 12:32:14,345 will process ui packet pointer-position
2013-04-24 12:32:14,346 will process ui packet pointer-position
2013-04-24 12:32:14,348 will process ui packet pointer-position
2013-04-24 12:32:14,350 will process ui packet pointer-position
2013-04-24 12:32:14,352 will process ui packet pointer-position
2013-04-24 12:32:14,353 will process ui packet pointer-position
2013-04-24 12:32:14,356 will process ui packet pointer-position
2013-04-24 12:32:14,357 will process ui packet pointer-position
2013-04-24 12:32:14,359 will process ui packet pointer-position
2013-04-24 12:32:14,361 will process ui packet pointer-position
2013-04-24 12:32:14,363 will process ui packet pointer-position
2013-04-24 12:32:14,365 will process ui packet pointer-position
2013-04-24 12:32:14,367 will process ui packet pointer-position
2013-04-24 12:32:14,369 will process ui packet pointer-position
2013-04-24 12:32:14,371 will process ui packet pointer-position
2013-04-24 12:32:14,373 will process ui packet pointer-position
2013-04-24 12:32:14,375 will process ui packet pointer-position
2013-04-24 12:32:14,377 will process ui packet pointer-position
2013-04-24 12:32:14,378 send_cursor(): default cursor - clearing it
2013-04-24 12:32:14,381 will process ui packet pointer-position
2013-04-24 12:32:14,383 will process ui packet pointer-position
2013-04-24 12:32:14,385 will process ui packet pointer-position
2013-04-24 12:32:14,386 will process ui packet pointer-position
2013-04-24 12:32:14,387 will process ui packet pointer-position
2013-04-24 12:32:14,391 will process ui packet pointer-position
2013-04-24 12:32:14,394 will process ui packet pointer-position
2013-04-24 12:32:14,397 will process ui packet pointer-position
2013-04-24 12:32:14,399 will process ui packet pointer-position
2013-04-24 12:32:14,402 will process ui packet pointer-position
2013-04-24 12:32:14,404 will process ui packet pointer-position
2013-04-24 12:32:14,408 will process ui packet pointer-position
2013-04-24 12:32:14,412 will process ui packet pointer-position
2013-04-24 12:32:14,414 will process ui packet pointer-position
2013-04-24 12:32:14,417 will process ui packet pointer-position
2013-04-24 12:32:14,421 will process ui packet pointer-position
2013-04-24 12:32:14,425 will process ui packet pointer-position
2013-04-24 12:32:14,429 will process ui packet pointer-position
2013-04-24 12:32:14,434 will process ui packet pointer-position
2013-04-24 12:32:14,437 will process ui packet pointer-position
2013-04-24 12:32:14,441 will process ui packet pointer-position
2013-04-24 12:32:14,445 will process ui packet pointer-position
2013-04-24 12:32:14,450 will process ui packet pointer-position
2013-04-24 12:32:14,453 will process ui packet pointer-position
2013-04-24 12:32:14,457 will process ui packet pointer-position
2013-04-24 12:32:14,462 will process ui packet pointer-position
2013-04-24 12:32:14,467 will process ui packet pointer-position
2013-04-24 12:32:14,472 will process ui packet pointer-position
2013-04-24 12:32:14,477 will process ui packet pointer-position
2013-04-24 12:32:14,483 will process ui packet pointer-position
2013-04-24 12:32:14,487 will process ui packet pointer-position
2013-04-24 12:32:14,491 will process ui packet pointer-position
2013-04-24 12:32:14,497 will process ui packet pointer-position
2013-04-24 12:32:14,501 will process ui packet pointer-position
2013-04-24 12:32:14,506 will process ui packet pointer-position
2013-04-24 12:32:14,511 will process ui packet pointer-position
2013-04-24 12:32:14,513 will process ui packet pointer-position
2013-04-24 12:32:14,518 will process ui packet pointer-position
2013-04-24 12:32:14,524 will process ui packet pointer-position
2013-04-24 12:32:14,526 process non-ui packet damage-sequence
2013-04-24 12:32:14,528 record_latency: took 4.1 ms round trip (3.7 just for echo), 0.0 for decoding of 1296 pixels, 1515 bytes sent over the network in 3.9 ms (3.5 ms for echo)
2013-04-24 12:32:14,529 will process ui packet pointer-position
2013-04-24 12:32:14,531 will process ui packet pointer-position
2013-04-24 12:32:14,535 will process ui packet pointer-position
2013-04-24 12:32:14,549 will process ui packet pointer-position
2013-04-24 12:32:14,558 will process ui packet pointer-position
2013-04-24 12:32:14,569 will process ui packet pointer-position
2013-04-24 12:32:14,576 will process ui packet pointer-position
2013-04-24 12:32:14,585 will process ui packet pointer-position
2013-04-24 12:32:14,603 will process ui packet pointer-position
2013-04-24 12:32:14,619 will process ui packet pointer-position
2013-04-24 12:32:14,621 will process ui packet pointer-position
2013-04-24 12:32:14,627 will process ui packet pointer-position
2013-04-24 12:32:14,630 will process ui packet pointer-position
2013-04-24 12:32:14,635 will process ui packet pointer-position
2013-04-24 12:32:14,643 will process ui packet pointer-position
2013-04-24 12:32:14,647 will process ui packet pointer-position
2013-04-24 12:32:14,653 will process ui packet pointer-position
2013-04-24 12:32:14,655 will process ui packet pointer-position
2013-04-24 12:32:14,660 will process ui packet pointer-position
2013-04-24 12:32:14,662 will process ui packet pointer-position
2013-04-24 12:32:14,666 will process ui packet pointer-position
2013-04-24 12:32:14,670 will process ui packet pointer-position
2013-04-24 12:32:14,674 will process ui packet pointer-position
2013-04-24 12:32:14,677 will process ui packet pointer-position
2013-04-24 12:32:14,683 will process ui packet pointer-position
2013-04-24 12:32:14,686 will process ui packet pointer-position
2013-04-24 12:32:14,690 will process ui packet pointer-position
2013-04-24 12:32:14,692 will process ui packet pointer-position
2013-04-24 12:32:14,696 will process ui packet pointer-position
2013-04-24 12:32:14,699 will process ui packet pointer-position
2013-04-24 12:32:14,707 will process ui packet pointer-position
2013-04-24 12:32:14,715 will process ui packet pointer-position
2013-04-24 12:32:15,036 will process ui packet focus
2013-04-24 12:32:15,037 _focus(36,()) has_focus=0
2013-04-24 12:32:15,037 Giving focus to client
2013-04-24 12:32:15,038 ... using XSetInputFocus
2013-04-24 12:32:15,038 ... using WM_TAKE_FOCUS
2013-04-24 12:32:15,038 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x1e19e60 (GdkWindow at 0x182cea0)>, 1090534376L
2013-04-24 12:32:15,061 will process ui packet button-action
2013-04-24 12:32:15,063 process non-ui packet damage-sequence
2013-04-24 12:32:15,063 record_latency: took 21.0 ms round trip (20.9 just for echo), 0.0 for decoding of 1296 pixels, 2236 bytes sent over the network in 20.7 ms (20.6 ms for echo)
2013-04-24 12:32:15,073 process non-ui packet damage-sequence
2013-04-24 12:32:15,074 record_latency: took 2.0 ms round trip (1.9 just for echo), 0.0 for decoding of 1296 pixels, 2452 bytes sent over the network in 1.5 ms (1.5 ms for echo)
2013-04-24 12:32:15,127 will process ui packet button-action
2013-04-24 12:32:15,183 do_child_configure_request_event(<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x1b15320 (GdkWindow at 0x182c000)>, 'send_event': 0, 'value_mask': 64L, 'detail': 0, 'height': 237, 'width': 482, 'window': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 'above': None, 'y': 0, 'x': 0, 'serial': 29108L, 'border_width': 0, 'type': 23, 'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
2013-04-24 12:32:15,183 Reconfigure on withdrawn window
2013-04-24 12:32:15,184 Found a potential client
2013-04-24 12:32:15,184 new window 0xc0043eL - 12583998
2013-04-24 12:32:15,185 CompositeHelper.__init__(<gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>,False)
2013-04-24 12:32:15,185 call_setup() adding event receiver
2013-04-24 12:32:15,185 invalidating named pixmap
2013-04-24 12:32:15,185 setup() corral_window=<gtk.gdk.Window object at 0x1e83b40 (GdkWindow at 0x1f1cb40)>
2013-04-24 12:32:15,186 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 'WM_TRANSIENT_FOR', 'WINDOW'),{}) WM_TRANSIENT_FOR
2013-04-24 12:32:15,186 Missing property WM_TRANSIENT_FOR (window)
2013-04-24 12:32:15,187 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, '_NET_WM_STATE', 'ATOM'),{}) _NET_WM_STATE
2013-04-24 12:32:15,188 Missing property _NET_WM_STATE (['atom'])
2013-04-24 12:32:15,188 reading initial value for WM_HINTS
2013-04-24 12:32:15,188 Property changed on 12583998: WM_HINTS
2013-04-24 12:32:15,188 wm_hints.input = 1
2013-04-24 12:32:15,188 reading initial value for WM_NORMAL_HINTS
2013-04-24 12:32:15,189 Property changed on 12583998: WM_NORMAL_HINTS
2013-04-24 12:32:15,189 reading initial value for WM_NAME
2013-04-24 12:32:15,189 Property changed on 12583998: WM_NAME
2013-04-24 12:32:15,192 reading initial value for _NET_WM_NAME
2013-04-24 12:32:15,192 Property changed on 12583998: _NET_WM_NAME
2013-04-24 12:32:15,193 reading initial value for WM_ICON_NAME
2013-04-24 12:32:15,193 Property changed on 12583998: WM_ICON_NAME
2013-04-24 12:32:15,193 reading initial value for _NET_WM_ICON_NAME
2013-04-24 12:32:15,193 Property changed on 12583998: _NET_WM_ICON_NAME
2013-04-24 12:32:15,194 reading initial value for _NET_WM_STRUT
2013-04-24 12:32:15,194 Property changed on 12583998: _NET_WM_STRUT
2013-04-24 12:32:15,194 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, '_NET_WM_STRUT_PARTIAL', 'CARDINAL'),{}) _NET_WM_STRUT_PARTIAL
2013-04-24 12:32:15,194 Missing property _NET_WM_STRUT_PARTIAL (strut-partial)
2013-04-24 12:32:15,197 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, '_NET_WM_STRUT', 'CARDINAL'),{}) _NET_WM_STRUT
2013-04-24 12:32:15,198 Missing property _NET_WM_STRUT (strut)
2013-04-24 12:32:15,198 reading initial value for _NET_WM_STRUT_PARTIAL
2013-04-24 12:32:15,198 Property changed on 12583998: _NET_WM_STRUT_PARTIAL
2013-04-24 12:32:15,206 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, '_NET_WM_STRUT_PARTIAL', 'CARDINAL'),{}) _NET_WM_STRUT_PARTIAL
2013-04-24 12:32:15,206 Missing property _NET_WM_STRUT_PARTIAL (strut-partial)
2013-04-24 12:32:15,206 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, '_NET_WM_STRUT', 'CARDINAL'),{}) _NET_WM_STRUT
2013-04-24 12:32:15,206 Missing property _NET_WM_STRUT (strut)
2013-04-24 12:32:15,207 Property changed on 12583998: _NET_WM_ICON
2013-04-24 12:32:15,207 _NET_WM_ICON changed on 12583998, re-reading
2013-04-24 12:32:15,210 icon is now <cairo.ImageSurface object at 0x1e6b470>
2013-04-24 12:32:15,211 setup() adding to save set
2013-04-24 12:32:15,211 setup() reparenting
2013-04-24 12:32:15,211 setup() geometry
2013-04-24 12:32:15,212 setup() resizing windows to 482x237
2013-04-24 12:32:15,213 call_setup() ended
2013-04-24 12:32:15,214 Discovered new ordinary window: <WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)> (geometry=(0, 0, 482, 237))
2013-04-24 12:32:15,214 window_types=['_NET_WM_WINDOW_TYPE_DIALOG']
2013-04-24 12:32:15,214 window_types=['_NET_WM_WINDOW_TYPE_DIALOG']
2013-04-24 12:32:15,215 new_window(new-window, <WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 37, 0, 0, 482, 237, ('title', 'pid', 'size-hints', 'class-instance', 'icon', 'client-machine', 'transient-for', 'window-type', 'modal'), None) metadata={'size-constraints': {'minimum-size': (482, 237)}, 'window-type': ['_NET_WM_WINDOW_TYPE_DIALOG'], 'modal': False, 'title': 'GnuCash', 'class-instance': ['gnucash', 'Gnucash'], 'client-machine': 'deblab', 'pid': 23209}
2013-04-24 12:32:15,215 send_window_icon(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>,37) icon=<cairo.ImageSurface object at 0x1e6b470>
2013-04-24 12:32:15,216 found new window icon: 48x48, sending as png=True
2013-04-24 12:32:15,221 Property changed on 12583998: _NET_WM_ALLOWED_ACTIONS
2013-04-24 12:32:15,222 Property changed on 12583998: _NET_FRAME_EXTENTS
2013-04-24 12:32:15,222 Property changed on 12583998: _NET_WM_STATE
2013-04-24 12:32:15,223 Property changed on 12583998: WM_STATE
2013-04-24 12:32:15,223 invalidating named pixmap
2013-04-24 12:32:15,264 Property changed on 12583998: WM_NORMAL_HINTS
2013-04-24 12:32:15,265 do_child_configure_request_event(<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x1e83b40 (GdkWindow at 0x1f1cb40)>, 'send_event': 0, 'value_mask': 12L, 'detail': 0, 'height': 279, 'width': 552, 'window': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 'above': None, 'y': 0, 'x': 0, 'serial': 29196L, 'border_width': 0, 'type': 23, 'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
2013-04-24 12:32:15,271 will process ui packet map-window
2013-04-24 12:32:15,271 DesktopManager.configure_window(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 2, 57, 482, 237)
2013-04-24 12:32:15,272 _update_client_geometry: owner()=<DesktopManager object at 0x1c7dcd0 (xpra+server+DesktopManager at 0x1ca6120)>
2013-04-24 12:32:15,272 _do_update_client_geometry: 482x237
2013-04-24 12:32:15,273 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,273 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,273 _do_update_client_geometry: size=(552, 279, 552, 279)
2013-04-24 12:32:15,273 will process ui packet configure-window
2013-04-24 12:32:15,274 Uh-oh, our size doesn't fit window sizing constraints: 482x237 vs 552x279
2013-04-24 12:32:15,274 _do_update_client_geometry: position=(0, 0)
2013-04-24 12:32:15,275 will process ui packet focus
2013-04-24 12:32:15,276 will process ui packet focus
2013-04-24 12:32:15,276 will process ui packet configure-window
2013-04-24 12:32:15,276 _update_client_geometry: owner()=<DesktopManager object at 0x1c7dcd0 (xpra+server+DesktopManager at 0x1ca6120)>
2013-04-24 12:32:15,276 _do_update_client_geometry: 482x237
2013-04-24 12:32:15,276 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,277 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,277 _do_update_client_geometry: size=(552, 279, 552, 279)
2013-04-24 12:32:15,277 Uh-oh, our size doesn't fit window sizing constraints: 482x237 vs 552x279
2013-04-24 12:32:15,277 process non-ui packet damage-sequence
2013-04-24 12:32:15,278 record_latency: took 9.5 ms round trip (9.4 just for echo), 0.0 for decoding of 1296 pixels, 2119 bytes sent over the network in 9.2 ms (9.1 ms for echo)
2013-04-24 12:32:15,278 _do_update_client_geometry: position=(2, 57)
2013-04-24 12:32:15,281 set_client_properties updating {} with {}
2013-04-24 12:32:15,286 Property changed on 12583998: WM_STATE
2013-04-24 12:32:15,287 WindowModel.composite_configure_event(<CompositeHelper object at 0x1e83a50 (wimpiggy+composite+CompositeHelper at 0x16b7480)>, <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 'send_event': 0, 'height': 279, 'width': 552, 'window': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 'y': 0, 'x': 0, 'serial': 29227L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
2013-04-24 12:32:15,288 BaseWindowModel.composite_configure_event(<CompositeHelper object at 0x1e83a50 (wimpiggy+composite+CompositeHelper at 0x16b7480)>,<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 'send_event': 0, 'height': 279, 'width': 552, 'window': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 'y': 0, 'x': 0, 'serial': 29227L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
2013-04-24 12:32:15,288 invalidating named pixmap
2013-04-24 12:32:15,288 invalidating named pixmap
2013-04-24 12:32:15,291 _process_configure_window([37, 2, 57, 482, 237, {'screen': 0, 'workspace': 0}]) old window geometry: (2, 57, 482, 237)
2013-04-24 12:32:15,291 DesktopManager.configure_window(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 2, 57, 482, 237)
2013-04-24 12:32:15,293 _update_client_geometry: owner()=<DesktopManager object at 0x1c7dcd0 (xpra+server+DesktopManager at 0x1ca6120)>
2013-04-24 12:32:15,294 _do_update_client_geometry: 482x237
2013-04-24 12:32:15,294 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,294 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,294 _do_update_client_geometry: size=(552, 279, 552, 279)
2013-04-24 12:32:15,294 Uh-oh, our size doesn't fit window sizing constraints: 482x237 vs 552x279
2013-04-24 12:32:15,298 _do_update_client_geometry: position=(2, 57)
2013-04-24 12:32:15,298 set_client_properties updating {} with {'screen': 0, 'workspace': 0}
2013-04-24 12:32:15,298 _focus(0,()) has_focus=36
2013-04-24 12:32:15,300 widget with focus: None
2013-04-24 12:32:15,300 Focus -> world window
2013-04-24 12:32:15,300 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x1e839b0 (GdkWindow at 0x182c6c0)>, 1090534638L
2013-04-24 12:32:15,302 _focus(37,()) has_focus=0
2013-04-24 12:32:15,302 _process_configure_window([37, 2, 57, 482, 237, {'screen': 0, 'workspace': 0}]) old window geometry: (2, 57, 482, 237)
2013-04-24 12:32:15,302 DesktopManager.configure_window(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 2, 57, 482, 237)
2013-04-24 12:32:15,302 _update_client_geometry: owner()=<DesktopManager object at 0x1c7dcd0 (xpra+server+DesktopManager at 0x1ca6120)>
2013-04-24 12:32:15,303 _do_update_client_geometry: 482x237
2013-04-24 12:32:15,303 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,303 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,303 _do_update_client_geometry: size=(552, 279, 552, 279)
2013-04-24 12:32:15,303 Uh-oh, our size doesn't fit window sizing constraints: 482x237 vs 552x279
2013-04-24 12:32:15,303 _do_update_client_geometry: position=(2, 57)
2013-04-24 12:32:15,311 set_client_properties updating {'screen': 0, 'workspace': 0} with {'screen': 0, 'workspace': 0}
2013-04-24 12:32:15,311 refreshing named pixmap
2013-04-24 12:32:15,334 will process ui packet configure-window
2013-04-24 12:32:15,349 Giving focus to client
2013-04-24 12:32:15,349 ... using XSetInputFocus
2013-04-24 12:32:15,351 ... using WM_TAKE_FOCUS
2013-04-24 12:32:15,351 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 1090534687L
2013-04-24 12:32:15,352 _process_configure_window([37, 2, 57, 552, 279, {'screen': 0, 'workspace': 0}]) old window geometry: (2, 57, 482, 237)
2013-04-24 12:32:15,352 DesktopManager.configure_window(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 2, 57, 552, 279)
2013-04-24 12:32:15,352 _update_client_geometry: owner()=<DesktopManager object at 0x1c7dcd0 (xpra+server+DesktopManager at 0x1ca6120)>
2013-04-24 12:32:15,352 _do_update_client_geometry: 552x279
2013-04-24 12:32:15,353 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,353 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,353 _do_update_client_geometry: size=(552, 279, 552, 279)
2013-04-24 12:32:15,353 _do_update_client_geometry: position=(2, 57)
2013-04-24 12:32:15,358 set_client_properties updating {'screen': 0, 'workspace': 0} with {'screen': 0, 'workspace': 0}
2013-04-24 12:32:15,395 will process ui packet configure-window
2013-04-24 12:32:15,395 will process ui packet configure-window
2013-04-24 12:32:15,397 _process_configure_window([37, 2, 57, 552, 279, {'screen': 0, 'workspace': 0}]) old window geometry: (2, 57, 552, 279)
2013-04-24 12:32:15,398 DesktopManager.configure_window(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 2, 57, 552, 279)
2013-04-24 12:32:15,398 _update_client_geometry: owner()=<DesktopManager object at 0x1c7dcd0 (xpra+server+DesktopManager at 0x1ca6120)>
2013-04-24 12:32:15,398 _do_update_client_geometry: 552x279
2013-04-24 12:32:15,398 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,399 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,399 _do_update_client_geometry: size=(552, 279, 552, 279)
2013-04-24 12:32:15,399 process non-ui packet damage-sequence
2013-04-24 12:32:15,400 record_latency: took 77.1 ms round trip (77.0 just for echo), 3.0 for decoding of 114234 pixels, 1031 bytes sent over the network in 73.2 ms (73.1 ms for echo)
2013-04-24 12:32:15,400 _do_update_client_geometry: position=(2, 57)
2013-04-24 12:32:15,403 set_client_properties updating {'screen': 0, 'workspace': 0} with {'screen': 0, 'workspace': 0}
2013-04-24 12:32:15,403 _process_configure_window([37, 2, 57, 552, 279, {'screen': 0, 'workspace': 0}]) old window geometry: (2, 57, 552, 279)
2013-04-24 12:32:15,403 DesktopManager.configure_window(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 2, 57, 552, 279)
2013-04-24 12:32:15,404 _update_client_geometry: owner()=<DesktopManager object at 0x1c7dcd0 (xpra+server+DesktopManager at 0x1ca6120)>
2013-04-24 12:32:15,404 _do_update_client_geometry: 552x279
2013-04-24 12:32:15,404 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,404 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 279), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 12:32:15,404 _do_update_client_geometry: size=(552, 279, 552, 279)
2013-04-24 12:32:15,404 _do_update_client_geometry: position=(2, 57)
2013-04-24 12:32:15,406 set_client_properties updating {'screen': 0, 'workspace': 0} with {'screen': 0, 'workspace': 0}
2013-04-24 12:32:15,495 process non-ui packet damage-sequence
2013-04-24 12:32:15,496 record_latency: took 149.8 ms round trip (149.8 just for echo), 74.0 for decoding of 154008 pixels, 534 bytes sent over the network in 74.9 ms (74.9 ms for echo)
2013-04-24 12:32:15,496 process non-ui packet damage-sequence
2013-04-24 12:32:15,496 record_latency: took 120.5 ms round trip (120.3 just for echo), 21.0 for decoding of 107550 pixels, 16874 bytes sent over the network in 98.8 ms (98.6 ms for echo)
2013-04-24 12:32:15,515 process non-ui packet damage-sequence
2013-04-24 12:32:15,515 record_latency: took 105.0 ms round trip (104.9 just for echo), 18.0 for decoding of 1296 pixels, 2195 bytes sent over the network in 86.4 ms (86.3 ms for echo)
2013-04-24 12:32:15,528 process non-ui packet damage-sequence
2013-04-24 12:32:15,528 record_latency: took 20.5 ms round trip (20.3 just for echo), 12.0 for decoding of 154008 pixels, 21479 bytes sent over the network in 8.2 ms (8.0 ms for echo)
2013-04-24 12:32:16,215 process non-ui packet damage-sequence
2013-04-24 12:32:16,216 record_latency: took 2.0 ms round trip (2.0 just for echo), 0.0 for decoding of 4380 pixels, 382 bytes sent over the network in 1.7 ms (1.6 ms for echo)
2013-04-24 12:32:16,577 will process ui packet pointer-position
2013-04-24 12:32:16,579 WindowModel.composite_configure_event(<CompositeHelper object at 0x1e81d20 (wimpiggy+composite+CompositeHelper at 0x16b7520)>, <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x1e83870 (GdkWindow at 0x1f1c7e0)>, 'send_event': 0, 'height': 755, 'width': 910, 'window': <gtk.gdk.Window object at 0x1e83870 (GdkWindow at 0x1f1c7e0)>, 'y': 57, 'x': 2, 'serial': 29592L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
2013-04-24 12:32:16,580 BaseWindowModel.composite_configure_event(<CompositeHelper object at 0x1e81d20 (wimpiggy+composite+CompositeHelper at 0x16b7520)>,<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x1e83870 (GdkWindow at 0x1f1c7e0)>, 'send_event': 0, 'height': 755, 'width': 910, 'window': <gtk.gdk.Window object at 0x1e83870 (GdkWindow at 0x1f1c7e0)>, 'y': 57, 'x': 2, 'serial': 29592L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
2013-04-24 12:32:16,580 invalidating named pixmap
2013-04-24 12:32:16,580 invalidating named pixmap
2013-04-24 12:32:16,582 will process ui packet pointer-position
2013-04-24 12:32:16,587 will process ui packet pointer-position
2013-04-24 12:32:16,590 will process ui packet pointer-position
2013-04-24 12:32:16,595 will process ui packet pointer-position
2013-04-24 12:32:16,597 will process ui packet pointer-position
2013-04-24 12:32:16,599 will process ui packet pointer-position
2013-04-24 12:32:16,601 will process ui packet pointer-position
2013-04-24 12:32:16,604 will process ui packet pointer-position
2013-04-24 12:32:16,605 will process ui packet pointer-position
2013-04-24 12:32:16,607 will process ui packet pointer-position
2013-04-24 12:32:16,609 will process ui packet pointer-position
2013-04-24 12:32:16,611 will process ui packet pointer-position
2013-04-24 12:32:16,613 will process ui packet pointer-position
2013-04-24 12:32:16,616 will process ui packet pointer-position
2013-04-24 12:32:16,617 process non-ui packet damage-sequence
2013-04-24 12:32:16,617 record_latency: took 1.9 ms round trip (1.8 just for echo), 0.0 for decoding of 4380 pixels, 142 bytes sent over the network in 1.6 ms (1.6 ms for echo)
2013-04-24 12:32:16,618 will process ui packet pointer-position
2013-04-24 12:32:16,622 refreshing named pixmap
2013-04-24 12:32:16,623 will process ui packet pointer-position
2013-04-24 12:32:16,623 will process ui packet pointer-position
2013-04-24 12:32:16,624 will process ui packet pointer-position
2013-04-24 12:32:16,625 will process ui packet pointer-position
2013-04-24 12:32:16,628 process non-ui packet damage-sequence
2013-04-24 12:32:16,628 record_latency: took 3.0 ms round trip (3.0 just for echo), 0.0 for decoding of 1296 pixels, 1537 bytes sent over the network in 2.7 ms (2.7 ms for echo)
2013-04-24 12:32:16,628 will process ui packet pointer-position
2013-04-24 12:32:16,630 will process ui packet pointer-position
2013-04-24 12:32:16,632 will process ui packet pointer-position
2013-04-24 12:32:16,633 will process ui packet pointer-position
2013-04-24 12:32:16,635 will process ui packet pointer-position
2013-04-24 12:32:16,639 will process ui packet pointer-position
2013-04-24 12:32:16,639 will process ui packet pointer-position
2013-04-24 12:32:16,642 will process ui packet pointer-position
2013-04-24 12:32:16,643 will process ui packet pointer-position
2013-04-24 12:32:16,645 will process ui packet pointer-position
2013-04-24 12:32:16,647 will process ui packet pointer-position
2013-04-24 12:32:16,649 will process ui packet pointer-position
2013-04-24 12:32:16,651 will process ui packet pointer-position
2013-04-24 12:32:16,653 will process ui packet pointer-position
2013-04-24 12:32:16,655 will process ui packet pointer-position
2013-04-24 12:32:16,657 will process ui packet pointer-position
2013-04-24 12:32:16,660 will process ui packet pointer-position
2013-04-24 12:32:16,661 will process ui packet pointer-position
2013-04-24 12:32:16,663 will process ui packet pointer-position
2013-04-24 12:32:16,665 will process ui packet pointer-position
2013-04-24 12:32:16,667 will process ui packet pointer-position
2013-04-24 12:32:16,670 will process ui packet pointer-position
2013-04-24 12:32:16,671 will process ui packet pointer-position
2013-04-24 12:32:16,673 will process ui packet pointer-position
2013-04-24 12:32:16,674 will process ui packet pointer-position
2013-04-24 12:32:16,676 will process ui packet pointer-position
2013-04-24 12:32:16,678 will process ui packet pointer-position
2013-04-24 12:32:16,680 will process ui packet pointer-position
2013-04-24 12:32:16,682 will process ui packet pointer-position
2013-04-24 12:32:16,684 will process ui packet pointer-position
2013-04-24 12:32:16,686 will process ui packet pointer-position
2013-04-24 12:32:16,740 will process ui packet pointer-position
2013-04-24 12:32:16,741 will process ui packet pointer-position
2013-04-24 12:32:16,742 will process ui packet pointer-position
2013-04-24 12:32:16,742 will process ui packet pointer-position
2013-04-24 12:32:16,744 will process ui packet pointer-position
2013-04-24 12:32:16,744 will process ui packet pointer-position
2013-04-24 12:32:16,745 will process ui packet pointer-position
2013-04-24 12:32:16,747 will process ui packet pointer-position
2013-04-24 12:32:16,748 will process ui packet pointer-position
2013-04-24 12:32:16,749 will process ui packet pointer-position
2013-04-24 12:32:16,750 will process ui packet pointer-position
2013-04-24 12:32:16,751 will process ui packet pointer-position
2013-04-24 12:32:16,752 will process ui packet pointer-position
2013-04-24 12:32:16,753 will process ui packet pointer-position
2013-04-24 12:32:16,754 will process ui packet pointer-position
2013-04-24 12:32:16,755 will process ui packet pointer-position
2013-04-24 12:32:16,756 will process ui packet pointer-position
2013-04-24 12:32:16,758 will process ui packet pointer-position
2013-04-24 12:32:16,759 will process ui packet pointer-position
2013-04-24 12:32:16,761 will process ui packet pointer-position
2013-04-24 12:32:16,762 will process ui packet pointer-position
2013-04-24 12:32:16,765 will process ui packet pointer-position
2013-04-24 12:32:16,765 will process ui packet pointer-position
2013-04-24 12:32:16,766 will process ui packet pointer-position
2013-04-24 12:32:16,768 will process ui packet pointer-position
2013-04-24 12:32:16,769 will process ui packet pointer-position
2013-04-24 12:32:16,772 will process ui packet pointer-position
2013-04-24 12:32:16,772 will process ui packet pointer-position
2013-04-24 12:32:16,773 will process ui packet pointer-position
2013-04-24 12:32:16,773 will process ui packet pointer-position
2013-04-24 12:32:16,773 will process ui packet pointer-position
2013-04-24 12:32:16,773 will process ui packet pointer-position
2013-04-24 12:32:16,773 will process ui packet pointer-position
2013-04-24 12:32:16,774 will process ui packet pointer-position
2013-04-24 12:32:16,774 will process ui packet pointer-position
2013-04-24 12:32:16,780 will process ui packet pointer-position
2013-04-24 12:32:16,781 will process ui packet pointer-position
2013-04-24 12:32:16,781 will process ui packet pointer-position
2013-04-24 12:32:16,782 will process ui packet pointer-position
2013-04-24 12:32:16,782 will process ui packet pointer-position
2013-04-24 12:32:16,790 will process ui packet pointer-position
2013-04-24 12:32:16,791 will process ui packet pointer-position
2013-04-24 12:32:16,792 will process ui packet pointer-position
2013-04-24 12:32:16,792 will process ui packet pointer-position
2013-04-24 12:32:16,793 send_cursor(): default cursor - clearing it
2013-04-24 12:32:16,795 will process ui packet pointer-position
2013-04-24 12:32:16,797 will process ui packet pointer-position
2013-04-24 12:32:16,798 will process ui packet pointer-position
2013-04-24 12:32:16,804 will process ui packet pointer-position
2013-04-24 12:32:16,805 process non-ui packet damage-sequence
2013-04-24 12:32:16,805 record_latency: took 13.0 ms round trip (12.9 just for echo), 0.0 for decoding of 2175 pixels, 1070 bytes sent over the network in 12.8 ms (12.7 ms for echo)
2013-04-24 12:32:16,813 process non-ui packet damage-sequence
2013-04-24 12:32:16,814 record_latency: took 2.2 ms round trip (2.1 just for echo), 0.0 for decoding of 2175 pixels, 538 bytes sent over the network in 1.9 ms (1.9 ms for echo)
2013-04-24 12:32:17,107 will process ui packet focus
2013-04-24 12:32:17,107 _focus(0,()) has_focus=37
2013-04-24 12:32:17,108 widget with focus: None
2013-04-24 12:32:17,108 Focus -> world window
2013-04-24 12:32:17,109 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x1e839b0 (GdkWindow at 0x182c6c0)>, 1090536446L
2013-04-24 12:32:17,126 process non-ui packet damage-sequence
2013-04-24 12:32:17,126 record_latency: took 2.7 ms round trip (2.7 just for echo), 0.0 for decoding of 4380 pixels, 406 bytes sent over the network in 2.3 ms (2.2 ms for echo)

Then I dismissed the dialog and clicked "Enter payment..." button again (dialod appeared broken, as on the new attached screenshot):

2013-04-24 12:32:19,566 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366770739566
2013-04-24 12:32:19,567 process non-ui packet ping_echo
2013-04-24 12:32:19,568 ping echo client load=(1110, 1610, 1660), measured server latency=1
2013-04-24 12:32:23,135 process non-ui packet ping
2013-04-24 12:32:23,636 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366770743636
2013-04-24 12:32:23,638 process non-ui packet ping_echo
2013-04-24 12:32:23,638 ping echo client load=(1100, 1600, 1660), measured server latency=2
2013-04-24 12:32:27,509 will process ui packet pointer-position
2013-04-24 12:32:27,511 will process ui packet pointer-position
2013-04-24 12:32:27,514 will process ui packet pointer-position
2013-04-24 12:32:27,515 will process ui packet pointer-position
2013-04-24 12:32:27,518 will process ui packet pointer-position
2013-04-24 12:32:27,556 will process ui packet pointer-position
2013-04-24 12:32:27,559 will process ui packet pointer-position
2013-04-24 12:32:27,562 will process ui packet pointer-position
2013-04-24 12:32:27,564 will process ui packet pointer-position
2013-04-24 12:32:27,567 will process ui packet pointer-position
2013-04-24 12:32:27,569 will process ui packet pointer-position
2013-04-24 12:32:27,572 will process ui packet pointer-position
2013-04-24 12:32:27,574 will process ui packet pointer-position
2013-04-24 12:32:27,575 will process ui packet pointer-position
2013-04-24 12:32:27,575 will process ui packet pointer-position
2013-04-24 12:32:27,578 will process ui packet pointer-position
2013-04-24 12:32:27,579 will process ui packet pointer-position
2013-04-24 12:32:27,581 will process ui packet pointer-position
2013-04-24 12:32:28,374 will process ui packet pointer-position
2013-04-24 12:32:28,377 will process ui packet pointer-position
2013-04-24 12:32:28,422 will process ui packet pointer-position
2013-04-24 12:32:28,424 will process ui packet pointer-position
2013-04-24 12:32:28,425 will process ui packet pointer-position
2013-04-24 12:32:28,425 will process ui packet pointer-position
2013-04-24 12:32:28,425 will process ui packet pointer-position
2013-04-24 12:32:28,426 will process ui packet pointer-position
2013-04-24 12:32:28,426 will process ui packet pointer-position
2013-04-24 12:32:28,426 will process ui packet pointer-position
2013-04-24 12:32:28,426 will process ui packet pointer-position
2013-04-24 12:32:28,427 will process ui packet pointer-position
2013-04-24 12:32:28,427 will process ui packet pointer-position
2013-04-24 12:32:28,427 will process ui packet pointer-position
2013-04-24 12:32:28,427 will process ui packet pointer-position
2013-04-24 12:32:28,436 will process ui packet pointer-position
2013-04-24 12:32:28,436 will process ui packet pointer-position
2013-04-24 12:32:28,436 will process ui packet pointer-position
2013-04-24 12:32:28,436 will process ui packet pointer-position
2013-04-24 12:32:28,437 will process ui packet pointer-position
2013-04-24 12:32:28,437 will process ui packet pointer-position
2013-04-24 12:32:28,437 will process ui packet pointer-position
2013-04-24 12:32:28,437 will process ui packet pointer-position
2013-04-24 12:32:28,437 will process ui packet pointer-position
2013-04-24 12:32:28,438 will process ui packet pointer-position
2013-04-24 12:32:28,438 will process ui packet pointer-position
2013-04-24 12:32:28,778 will process ui packet focus
2013-04-24 12:32:28,779 _focus(37,()) has_focus=0
2013-04-24 12:32:28,779 Giving focus to client
2013-04-24 12:32:28,779 ... using XSetInputFocus
2013-04-24 12:32:28,782 ... using WM_TAKE_FOCUS
2013-04-24 12:32:28,783 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, 1090548117L
2013-04-24 12:32:28,795 process non-ui packet damage-sequence
2013-04-24 12:32:28,796 record_latency: took 1.8 ms round trip (1.8 just for echo), 0.0 for decoding of 4380 pixels, 385 bytes sent over the network in 1.5 ms (1.5 ms for echo)
2013-04-24 12:32:29,012 will process ui packet pointer-position
2013-04-24 12:32:29,014 will process ui packet pointer-position
2013-04-24 12:32:29,019 will process ui packet pointer-position
2013-04-24 12:32:29,022 will process ui packet pointer-position
2013-04-24 12:32:29,025 will process ui packet pointer-position
2013-04-24 12:32:29,027 will process ui packet pointer-position
2013-04-24 12:32:29,028 will process ui packet pointer-position
2013-04-24 12:32:29,029 will process ui packet pointer-position
2013-04-24 12:32:29,032 will process ui packet pointer-position
2013-04-24 12:32:29,034 will process ui packet pointer-position
2013-04-24 12:32:29,036 will process ui packet pointer-position
2013-04-24 12:32:29,037 will process ui packet pointer-position
2013-04-24 12:32:29,040 will process ui packet pointer-position
2013-04-24 12:32:29,041 will process ui packet pointer-position
2013-04-24 12:32:29,043 will process ui packet pointer-position
2013-04-24 12:32:29,045 will process ui packet pointer-position
2013-04-24 12:32:29,047 will process ui packet pointer-position
2013-04-24 12:32:29,050 will process ui packet pointer-position
2013-04-24 12:32:29,052 will process ui packet pointer-position
2013-04-24 12:32:29,054 will process ui packet pointer-position
2013-04-24 12:32:29,056 will process ui packet pointer-position
2013-04-24 12:32:29,058 will process ui packet pointer-position
2013-04-24 12:32:29,060 will process ui packet pointer-position
2013-04-24 12:32:29,063 will process ui packet pointer-position
2013-04-24 12:32:29,066 will process ui packet pointer-position
2013-04-24 12:32:29,068 will process ui packet pointer-position
2013-04-24 12:32:29,069 will process ui packet pointer-position
2013-04-24 12:32:29,071 will process ui packet pointer-position
2013-04-24 12:32:29,073 will process ui packet pointer-position
2013-04-24 12:32:29,075 will process ui packet pointer-position
2013-04-24 12:32:29,077 will process ui packet pointer-position
2013-04-24 12:32:29,079 will process ui packet pointer-position
2013-04-24 12:32:29,081 will process ui packet pointer-position
2013-04-24 12:32:29,083 will process ui packet pointer-position
2013-04-24 12:32:29,084 will process ui packet pointer-position
2013-04-24 12:32:29,091 will process ui packet pointer-position
2013-04-24 12:32:29,092 will process ui packet pointer-position
2013-04-24 12:32:29,093 process non-ui packet damage-sequence
2013-04-24 12:32:29,094 record_latency: took 3.7 ms round trip (3.7 just for echo), 0.0 for decoding of 1296 pixels, 1515 bytes sent over the network in 3.5 ms (3.4 ms for echo)
2013-04-24 12:32:29,094 will process ui packet pointer-position
2013-04-24 12:32:29,095 will process ui packet pointer-position
2013-04-24 12:32:29,097 will process ui packet pointer-position
2013-04-24 12:32:29,099 will process ui packet pointer-position
2013-04-24 12:32:29,101 will process ui packet pointer-position
2013-04-24 12:32:29,103 will process ui packet pointer-position
2013-04-24 12:32:29,109 will process ui packet pointer-position
2013-04-24 12:32:29,109 will process ui packet pointer-position
2013-04-24 12:32:29,114 will process ui packet pointer-position
2013-04-24 12:32:29,117 will process ui packet pointer-position
2013-04-24 12:32:29,119 will process ui packet pointer-position
2013-04-24 12:32:29,144 will process ui packet pointer-position
2013-04-24 12:32:29,566 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366770749566
2013-04-24 12:32:29,568 process non-ui packet ping_echo
2013-04-24 12:32:29,568 ping echo client load=(1010, 1570, 1650), measured server latency=2
2013-04-24 12:32:29,591 process non-ui packet damage-sequence
2013-04-24 12:32:29,591 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 4380 pixels, 159 bytes sent over the network in 1.7 ms (1.6 ms for echo)
2013-04-24 12:32:29,639 will process ui packet pointer-position
2013-04-24 12:32:29,659 will process ui packet pointer-position
2013-04-24 12:32:29,670 will process ui packet pointer-position
2013-04-24 12:32:29,700 will process ui packet pointer-position
2013-04-24 12:32:29,717 will process ui packet pointer-position
2013-04-24 12:32:29,723 will process ui packet pointer-position
2013-04-24 12:32:29,752 will process ui packet pointer-position
2013-04-24 12:32:29,760 will process ui packet pointer-position
2013-04-24 12:32:29,776 will process ui packet pointer-position
2013-04-24 12:32:29,784 will process ui packet key-action
2013-04-24 12:32:29,785 process_key_action([42, 37, 'Escape', True, (), 65307, '\x1b', 9, 0, 0]) server keycode=9
2013-04-24 12:32:29,785 _focus(37,None) has_focus=37
2013-04-24 12:32:29,786 handle_key(37,True,Escape,65307,9,())
2013-04-24 12:32:29,786 handle keycode pressing 9: key Escape
2013-04-24 12:32:29,790 handle keycode unpressing 9: key Escape
2013-04-24 12:32:29,806 Client window unmapped
2013-04-24 12:32:29,807 unmanaging window: <WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)> (<gtk.gdk.Window object at 0x1e83b40 (GdkWindow at 0x1f1cb40)> - <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>)
2013-04-24 12:32:29,809 will process ui packet focus
2013-04-24 12:32:29,808 Ignoring X error: BadWindow on <built-in function XDeleteProperty>
2013-04-24 12:32:29,810 Ignoring X error: BadWindow on <built-in function XDeleteProperty>
2013-04-24 12:32:29,811 Ignoring X error: BadWindow on <built-in function XDeleteProperty>
2013-04-24 12:32:29,811 Ignoring X error: BadWindow on <built-in function XDeleteProperty>
2013-04-24 12:32:29,811 Ignoring X error: BadWindow on <built-in function XRemoveFromSaveSet>
2013-04-24 12:32:29,812 Ignoring X error: BadWindow on <built-in function sendConfigureNotify>
2013-04-24 12:32:29,812 do_unmanaged(False) damage_forward_handle=529, composite=<CompositeHelper object at 0x1e83a50 (wimpiggy+composite+CompositeHelper at 0x16b7480)>
2013-04-24 12:32:29,812 invalidating named pixmap
2013-04-24 12:32:29,813 Ignoring X error: BadWindow on <built-in function xcomposite_unredirect_window>
2013-04-24 12:32:29,814 Ignoring X error: BadDamage (invalid Damage parameter)

xpra-info:

auto_refresh=250
batch_delay.50p=0
batch_delay.80p=0
batch_delay.90p=1
batch_delay.avg=0
batch_delay.cur=0
batch_delay.max=1
batch_delay.min=0
bell=1
build_bit=64bit
build_cpu=Intel(R) Pentium(R) D CPU 3.00GHz
build_date=2013-04-23
built_by=hawk
built_on=deblab
client.platform.machine=x86_64
client.platform.processor=
client.platform.release=3.8-trunk-amd64
client_bell=1
client_clipboard=1
client_connection=
client_cursors=1
client_encodings=x264,vpx,png,jpeg,rgb24,webp
client_hostname=deblab
client_idle_time=244
client_latency.50p=7
client_latency.80p=62
client_latency.90p=93
client_latency.absmin=1
client_latency.avg=30
client_latency.cur=1
client_latency.max=199
client_latency.min=1
client_notifications=1
client_ping_latency.50p=2
client_ping_latency.80p=2
client_ping_latency.90p=2
client_ping_latency.avg=3
client_ping_latency.cur=1
client_ping_latency.max=75
client_ping_latency.min=1
client_type=Python/Gtk2
client_uuid=60c3cd48885ffebb37f240eb99f3ae71b33f0587
client_version=0.9.0
clients=1
clipboard=0
cursors=1
damage_data_queue_size.50p=0
damage_data_queue_size.80p=0
damage_data_queue_size.90p=0
damage_data_queue_size.avg=0
damage_data_queue_size.cur=0
damage_data_queue_size.current=0
damage_data_queue_size.max=6
damage_data_queue_size.min=0
damage_in_latency.90p=66
damage_in_latency.avg=11
damage_in_latency.cur=0
damage_in_latency.max=130
damage_in_latency.min=0
damage_out_latency.90p=66
damage_out_latency.avg=12
damage_out_latency.cur=2
damage_out_latency.max=130
damage_out_latency.min=0
damage_packet_queue_size.50p=0
damage_packet_queue_size.80p=0
damage_packet_queue_size.90p=0
damage_packet_queue_size.avg=0
damage_packet_queue_size.cur=0
damage_packet_queue_size.current=0
damage_packet_queue_size.max=2
damage_packet_queue_size.min=0
encoding.client_options=1
encoding.initial_quality=70
encoding.min-quality=70
encoding.min-speed=0
encoding.rgb24zlib=1
encoding.supports_delta=['png', 'rgb24']
encoding.uses_swscale=0
encoding.x264.I420.profile=high
encodings=x264,vpx,png,jpeg,rgb24,webp
gtk_version=[2, 24, 10]
hostname=deblab
info_thread[0]=write
info_thread[1]=read
info_thread[2]=parse
info_threads=3
input_bytecount=83718
input_packetcount=2492
input_raw_packetcount=2444
key_repeat_delay=660
key_repeat_interval=40
keyboard=1
keyboard_sync=0
local_modifications=unknown
max_desktop_size=[5120, 3200]
memory.children.idrss=0
memory.children.inblock=3248
memory.children.isrss=0
memory.children.ixrss=0
memory.children.majflt=34
memory.children.maxrss=23728
memory.children.minflt=20717
memory.children.msgrcv=0
memory.children.msgsnd=0
memory.children.nivcsw=575
memory.children.nsignals=0
memory.children.nswap=0
memory.children.nvcsw=333
memory.children.oublock=32
memory.children.stime=0
memory.children.utime=0
memory.server.idrss=0
memory.server.inblock=1544
memory.server.isrss=0
memory.server.ixrss=0
memory.server.majflt=8
memory.server.maxrss=47404
memory.server.minflt=20518
memory.server.msgrcv=0
memory.server.msgsnd=0
memory.server.nivcsw=22250
memory.server.nsignals=0
memory.server.nswap=0
memory.server.nvcsw=28856
memory.server.oublock=2544
memory.server.stime=1
memory.server.utime=6
microphone.state=disabled
notifications=0
output_bytecount=2899123
output_mmap_bytecount=0
output_packetcount=723
output_raw_packetcount=1287
password_file=
pixels_encoded_per_second=13688902
platform=linux2
potential_clients=0
pulseaudio=1
pygtk_version=[2, 24, 0]
python_version=2.7.4
randr=1
revision=unknown
root_window_size=[4800, 1200]
server_ping_latency.50p=2
server_ping_latency.80p=2
server_ping_latency.90p=2
server_ping_latency.avg=2
server_ping_latency.cur=2
server_ping_latency.max=44
server_ping_latency.min=1
server_type=gtk-x11
session_name=
speaker.state=disabled
start_time=1366770579
thread[0]=MainThread
thread[1]=write
thread[2]=format
thread[3]=Dummy-1
thread[4]=read
thread[5]=encode
thread[6]=calculate_delay
thread[7]=format
thread[8]=parse
threads=9
version=0.9.0
window[36].batch_delay.90p=0
window[36].batch_delay.avg=0
window[36].batch_delay.cur=0
window[36].batch_delay.max=0
window[36].batch_delay.min=0
window[36].class-instance=['gnucash', 'Gnucash']
window[36].client-machine=deblab
window[36].compression_pixels_per_ns.avg=76
window[36].compression_pixels_per_ns.max=763
window[36].compression_pixels_per_ns.min=59
window[36].compression_pixels_per_ns[rgb24].avg=76
window[36].compression_pixels_per_ns[rgb24].max=763
window[36].compression_pixels_per_ns[rgb24].min=59
window[36].compression_ratio_pct.avg=1
window[36].compression_ratio_pct.max=61
window[36].compression_ratio_pct.min=0
window[36].compression_ratio_pct[rgb24].avg=1
window[36].compression_ratio_pct[rgb24].max=61
window[36].compression_ratio_pct[rgb24].min=0
window[36].damage_in_latency.90p=90
window[36].damage_in_latency.avg=16
window[36].damage_in_latency.cur=1
window[36].damage_in_latency.max=130
window[36].damage_in_latency.min=0
window[36].damage_out_latency.90p=90
window[36].damage_out_latency.avg=17
window[36].damage_out_latency.cur=2
window[36].damage_out_latency.max=130
window[36].damage_out_latency.min=0
window[36].dimensions=[910, 755]
window[36].encoding=rgb24
window[36].minimum-size=[592, 541]
window[36].modal=0
window[36].override-redirect=0
window[36].pid=23209
window[36].pixels_encoded_per_second=13136028
window[36].pixels_encoded_per_second[rgb24]=13136028
window[36].title=gnucash-test.gnucash - View Invoice - 0003 - GnuCash
window[36].total_frames[rgb24]=18
window[36].total_pixels[rgb24]=2087262
window[36].tray=0
window[36].window-type=['_NET_WM_WINDOW_TYPE_NORMAL']
window[36].xid=0xc00309L
window[38].batch_delay.90p=7
window[38].batch_delay.avg=3
window[38].batch_delay.cur=2
window[38].batch_delay.max=7
window[38].batch_delay.min=0
window[38].class-instance=['gnucash', 'Gnucash']
window[38].client-machine=deblab
window[38].compression_pixels_per_ns.avg=60
window[38].compression_pixels_per_ns.max=99
window[38].compression_pixels_per_ns.min=36
window[38].compression_pixels_per_ns[rgb24].avg=60
window[38].compression_pixels_per_ns[rgb24].max=99
window[38].compression_pixels_per_ns[rgb24].min=36
window[38].compression_ratio_pct.avg=1
window[38].compression_ratio_pct.max=4
window[38].compression_ratio_pct.min=0
window[38].compression_ratio_pct[rgb24].avg=1
window[38].compression_ratio_pct[rgb24].max=4
window[38].compression_ratio_pct[rgb24].min=0
window[38].damage_in_latency.90p=12
window[38].damage_in_latency.avg=4
window[38].damage_in_latency.cur=0
window[38].damage_in_latency.max=17
window[38].damage_in_latency.min=0
window[38].damage_out_latency.90p=12
window[38].damage_out_latency.avg=4
window[38].damage_out_latency.cur=1
window[38].damage_out_latency.max=18
window[38].damage_out_latency.min=0
window[38].dimensions=[552, 279]
window[38].encoding=rgb24
window[38].minimum-size=[552, 279]
window[38].modal=0
window[38].override-redirect=0
window[38].pid=23209
window[38].pixels_encoded_per_second=16630272
window[38].pixels_encoded_per_second[rgb24]=16630272
window[38].title=GnuCash
window[38].total_frames[rgb24]=11
window[38].total_pixels[rgb24]=497064
window[38].tray=0
window[38].window-type=['_NET_WM_WINDOW_TYPE_DIALOG']
window[38].xid=0xc004e0L
window[39].batch_delay.90p=0
window[39].batch_delay.avg=0
window[39].batch_delay.cur=0
window[39].batch_delay.max=0
window[39].batch_delay.min=0
window[39].compression_pixels_per_ns.avg=73
window[39].compression_pixels_per_ns.max=73
window[39].compression_pixels_per_ns.min=73
window[39].compression_pixels_per_ns[rgb24].avg=73
window[39].compression_pixels_per_ns[rgb24].max=73
window[39].compression_pixels_per_ns[rgb24].min=73
window[39].compression_ratio_pct.avg=8
window[39].compression_ratio_pct.max=8
window[39].compression_ratio_pct.min=8
window[39].compression_ratio_pct[rgb24].avg=8
window[39].compression_ratio_pct[rgb24].max=8
window[39].compression_ratio_pct[rgb24].min=8
window[39].damage_in_latency.90p=0
window[39].damage_in_latency.avg=0
window[39].damage_in_latency.cur=0
window[39].damage_in_latency.max=0
window[39].damage_in_latency.min=0
window[39].damage_out_latency.90p=2
window[39].damage_out_latency.avg=2
window[39].damage_out_latency.cur=2
window[39].damage_out_latency.max=2
window[39].damage_out_latency.min=2
window[39].dimensions=[282, 22]
window[39].encoding=rgb24
window[39].override-redirect=1
window[39].pixels_encoded_per_second=13545789
window[39].pixels_encoded_per_second[rgb24]=13545789
window[39].total_frames[rgb24]=1
window[39].total_pixels[rgb24]=6204
window[39].tray=0
window[39].window-type=['_NET_WM_WINDOW_TYPE_TOOLTIP']
window[39].xid=0xc00571L
windows=3
Connection lost
connection closed after 0 packets received (2595 bytes) and 1 packets sent (629 bytes)

xwininfo:


xwininfo: Window id: 0xc004e0 "GnuCash"

  Absolute upper-left X:  524
  Absolute upper-left Y:  487
  Relative upper-left X:  0
  Relative upper-left Y:  0
  Width: 552
  Height: 279
  Depth: 24
  Visual: 0x21
  Visual Class: TrueColor
  Border width: 0
  Class: InputOutput
  Colormap: 0x20 (installed)
  Bit Gravity State: NorthWestGravity
  Window Gravity State: NorthWestGravity
  Backing Store State: NotUseful
  Save Under State: no
  Map State: IsViewable
  Override Redirect State: no
  Corners:  +524+487  -3724+487  -3724-434  +524-434
  -geometry 552x279+0+0

xprop:

WM_STATE(CARDINAL):
      window state: Normal
      icon window: 0x0
_NET_WM_STATE(ATOM) = 
_NET_FRAME_EXTENTS(CARDINAL) = 0, 0, 0, 0
_NET_WM_ALLOWED_ACTIONS(ATOM) = _NET_WM_ACTION_CLOSE
WM_HINTS(WM_HINTS):
      Client accepts input or input focus: True
      Initial state is Normal State.
      bitmap id # to use for icon: 0xc0030c
      bitmap id # of mask for icon: 0xc0030d
      window id # of group leader: 0xc00001
XdndAware(ATOM) = BITMAP
_MOTIF_DRAG_RECEIVER_INFO(_MOTIF_DRAG_RECEIVER_INFO) = 0x6c, 0x0, 0x5, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x10, 0x0, 0x0, 0x0
_NET_WM_ICON(CARDINAL) =  Icon (16 x 16):
   ▒▒▒▒▒▒▒▒▒▒▒▒▒  
  ▒░           ░▒ 
  ▒             ▒ 
  ▒ ░           ▒ 
  ▒ ░           ▒ 
  ▒ ░           ▒ 
  ▒ ░ ▒▒  ░ ░░▒░▒ 
  ▒ ░▒░░▒▒ ░░   ░░
  ▒ ░░  ░░ ░░   ░░
  ▒ ░      ░░▒▒▒▒░
  ▒ ░      ░░   ░░
  ▒ ░      ░▒▒▒▒▒░
  ▒ ░░░░░░░▒░   ░░
  ▒░       ░▒▒▒▒▒░
   ▒▒▒▒▒▒▒▒▒░░ ░░░
            ░▒▒▒░ 

  Icon (32 x 32):

       ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒     
      ▒░                    ░▒    
      ▒                      ▒    
      ▒ ░                    ▒    
      ▒ ░                    ▒    
      ▒ ░                    ▒    
      ▒ ░                    ▒    
      ▒ ░                    ▒    
      ▒ ░           ░        ▒    
      ▒ ░   ░       ░     ░░▒▒░   
      ▒ ░  ░░▒░    ▒     ░░░  ░░  
      ▒ ░  ░  ░▒░ ░░     ▒      ▒ 
      ▒ ░ ▒     ░▒▒      ░▒░  ░▒░ 
      ▒ ░░░       ░      ▒░░▒▒░░▒ 
      ▒ ░▒               ░▒░  ░▒░ 
      ▒ ░░               ▒░░▒▒░░▒ 
      ▒ ░                ░▒░  ░▒░ 
     ▒▒▒▒▒▒▒▒▒▒▒▒▒░      ▒░░▒▒░░▒ 
    ▒▒░░░░░▒▒░░░░░▒    ░░▒▒░░ ░▒░ 
    ▒░░░▒▒▒░░▒▒▒░░▒   ░▒░  ░▒▒░░▒ 
   ░▒░░▒▒▒▒▒▒▒▒▒▒▒▒▒▒░▒      ▒░▒░ 
   ▒▒▒▒▒░░░░░▒░░░░░▒▒ ░▒░  ░▒▒░░▒ 
   ▒▒▒▒░░░▒▒▒░░▒▒▒░░▒ ▒░░▒▒░░▒░▒░ 
   ▒▒▒▒░░░░░▒░ ▒░░░░▒▒▒▒░  ░▒▒░░▒ 
   ▒▒▒▒▒▒▒▒▒▒  ▒▒▒▒▒▒▒▒░░▒▒░░▒░▒░ 
   ▒▒▒▒▒▒▒▒▒▒  ▒▒▒▒▒▒▒░▒░  ░▒▒░░▒ 
     ▒▒▒▒▒▒▒▒  ▒▒▒▒▒▒▒▒░░▒▒░░▒░▒░ 
     ▒▒▒▒▒▒▒▒░░▒▒▒▒▒▒▒░▒░  ░▒▒░░  
     ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒ ░░▒▒░      

  Icon (48 x 48):

         ░▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒░       
        ░░                                ░░      
        ▒                                  ▒      
        ▒                                  ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                               ▒      
        ▒  ░                 ░░            ▒      
        ▒  ░                 ░             ▒      
        ▒  ░    ░░          ░              ▒      
        ▒  ░    ▒░▒░       ░░           ░░░▒░░    
        ▒  ░   ░░  ░▒░    ░▒           ▒░     ░▒  
        ▒  ░  ░▒     ░▒░░░▒░░░░       ▒         ░ 
        ▒  ░  ░░       ▒▒░▒           ▒         ▒ 
        ▒  ░ ░░         ░▒░           ▒▒░     ░▒▒ 
        ▒  ░ ▒            ░           ▒░░░▒▒▒░░░▒ 
        ▒  ░▒░            ░           ▒▒░░░░░░░▒▒ 
        ▒  ░▒           ░░░░░░        ▒░░░▒▒▒░░░▒ 
        ▒  ░░                         ▒▒░░░░░░░▒▒ 
        ▒  ░                          ▒░░░▒▒▒░░░▒ 
      ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒           ▒▒░░░░░░░▒▒ 
     ▒▒░░░░░░░▒  ▒░░░░░░░░▒░       ░░░▒▒░░▒▒▒░░░▒ 
     ▒░▒▒▒░▒▒▒▒  ▒▒▒▒░▒▒▒░▒▒░░░░░░▒░     ░▒░░░░▒▒ 
    ░▒░░░░░▒▒▒░  ░▒▒▒░░░░░▒░     ░         ▒▒░░░▒ 
    ▒░▒▒▒░░▒▒▒░  ░▒▒▒░░▒▒▒░▒     ▒         ▒░░░▒▒ 
   ░▒░░░░▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒   ▒▒░     ░▒▒▒░░░▒ 
   ▒▒▒▒▒▒▒░░░░░░░░▒  ▒░░░░░░░▒░  ▒░░░▒▒▒░░░▒░░░▒▒ 
   ▒▒▒▒▒▒░░▒▒▒░▒▒▒▒  ▒▒▒▒▒▒▒░░▒  ▒▒░░░░░░░▒▒▒░░░▒ 
   ▒▒▒▒▒▒░░░░░░▒▒▒░  ░▒▒▒░░░░░▒  ▒░░░▒▒▒░░░▒░░░▒▒ 
   ▒▒▒▒▒▒░▒▒▒░░▒▒▒░  ░▒▒▒░▒▒▒░▒▒▒▒▒░░░░░░░▒▒▒░░░▒ 
   ▒▒▒▒▒░░░░░░░░░▒    ▒░░░░░░░░▒ ▒░░░▒▒▒░░░▒░░░▒▒ 
   ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒    ▒▒▒▒▒▒▒▒▒▒░▒▒░░░░░░░▒▒▒░░░▒ 
   ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒    ▒▒▒▒▒▒▒▒▒▒ ▒░░░▒▒▒░░░▒░░░▒  
       ▒▒▒▒▒▒▒▒▒▒▒    ▒▒▒▒▒▒▒▒▒▒ ▒▒░░░░░░░▒▒▒░░   
       ▒▒▒▒▒▒▒▒▒▒▒    ▒▒▒▒▒▒▒▒▒▒ ▒░░░▒▒▒░░░▒      
       ▒▒▒▒▒▒▒▒▒▒▒░░░░▒▒▒▒▒▒▒▒▒▒ ░▒░░░░░░░▒       
       ▒▒▒▒▒▒▒▒▒▒▒░░░░▒▒▒▒▒▒▒▒▒▒   ░░▒▒▒░░        
       ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒                  

_NET_WM_SYNC_REQUEST_COUNTER(CARDINAL) = 12584162
_NET_WM_WINDOW_TYPE(ATOM) = _NET_WM_WINDOW_TYPE_DIALOG
_NET_WM_USER_TIME_WINDOW(WINDOW): window id # 0xc004e1
WM_CLIENT_LEADER(WINDOW): window id # 0xc00001
_NET_WM_PID(CARDINAL) = 23209
WM_LOCALE_NAME(STRING) = "en_AU.UTF-8"
WM_CLIENT_MACHINE(STRING) = "deblab"
WM_NORMAL_HINTS(WM_SIZE_HINTS):
      program specified minimum size: 552 by 279
      window gravity: NorthWest
WM_PROTOCOLS(ATOM): protocols  WM_DELETE_WINDOW, WM_TAKE_FOCUS, _NET_WM_PING, _NET_WM_SYNC_REQUEST
WM_CLASS(STRING) = "gnucash", "Gnucash"
WM_ICON_NAME(STRING) = "GnuCash"
_NET_WM_ICON_NAME(UTF8_STRING) = "GnuCash"
WM_NAME(STRING) = "GnuCash"
_NET_WM_NAME(UTF8_STRING) = "GnuCash"

Dialog looks OK on screenshot taken with xpra screenshot but on screen it is exactly like on the attached screenshot taken by ksnapshot.

totaam commented 11 years ago

2013-04-24 03:56:53: onlyjob uploaded file xpra_gnucash-enter-payment1.png (35.3 KiB)

xpra_gnucash-enter-payment1.png

totaam commented 11 years ago

2013-04-24 03:59:58: onlyjob commented

Last screenshot and logs were taken using Xpra r3131: [[Image(/raw-attachment/ticket/252/xpra_gnucash-enter-payment1.png)]]

totaam commented 11 years ago

2013-04-24 06:57:29: totaam commented

Trimmed debug log:

(..)
will process ui packet button-action
(..)
do_child_configure_request_event(<AdHocStruct object, contents: \
    {'delivered_to': <gtk.gdk.Window object at 0x1b15320 (GdkWindow at 0x182c000)>, \
     'send_event': 0, 'value_mask': 64L, 'detail': 0, \
     'height': 237, 'width': 482, \
     'window': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, \
     'above': None, 'y': 0, 'x': 0, 'serial': 29108L, 'border_width': 0, 'type': 23, \
     'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
(..)
Discovered new ordinary window: <WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)> \
    (geometry=(0, 0, 482, 237))
(..)
new_window(new-window, <WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, \
    37, 0, 0, 482, 237, \
    ('title', 'pid', 'size-hints', 'class-instance', 'icon', 'client-machine', 'transient-for', 'window-type', 'modal'), \
    None) \
    metadata={'size-constraints': {'minimum-size': (482, 237)}, 'window-type': ['_NET_WM_WINDOW_TYPE_DIALOG'], \
     'modal': False, 'title': 'GnuCash', 'class-instance': ['gnucash', 'Gnucash'], 'client-machine': 'deblab', 'pid': 23209}
(..)
do_child_configure_request_event(<AdHocStruct object, \
    contents: {'delivered_to': <gtk.gdk.Window object at 0x1e83b40 (GdkWindow at 0x1f1cb40)>, \
     'send_event': 0, 'value_mask': 12L, 'detail': 0, 'height': 279, 'width': 552, \
     'window': <gtk.gdk.Window object at 0x1e83910 (GdkWindow at 0x1f1c000)>, \
     'above': None, 'y': 0, 'x': 0, 'serial': 29196L, 'border_width': 0, 'type': 23, \
     'display': <gtk.gdk.Display object at 0x19cd140 (GdkDisplayX11 at 0x1a54220)>}>)
(..)
_do_update_client_geometry: size=(552, 279, 552, 279)
will process ui packet configure-window
Uh-oh, our size doesn't fit window sizing constraints: 482x237 vs 552x279
(..)
_process_configure_window([37, 2, 57, 482, 237, {'screen': 0, 'workspace': 0}]) \
    old window geometry: (2, 57, 482, 237)
_do_update_client_geometry: 482x237
_do_update_client_geometry: size=(552, 279, 552, 279)
Uh-oh, our size doesn't fit window sizing constraints: 482x237 vs 552x279
(..)
_do_update_client_geometry: size=(552, 279, 552, 279)
(..)
DesktopManager.configure_window(<WindowModel object at 0x1e83aa0 (wimpiggy+window+WindowModel at 0x16b7ce0)>, 2, 57, 482, 237)

I think the client-side xpra and the application are in a race to decide the dimensions of the window, the client opens the window with the size 482x237 which is also the size that the client uses (since the correct size is only set afterwards), but in the meantime, the application resizes itself to 552x279. DesktopManager seems to have only the old size and does not get updated to the correct size.

The other log is mostly empty, I think the window is unmapped and then mapped again, when that happens we use the desktop manager for the damage region size?... and therefore the wrong size?

Does this patch help:

--- src/xpra/server.py    (revision 3132)
+++ src/xpra/server.py    (working copy)
@@ -86,6 +86,10 @@
             model.ownership_election()
         self._models[model].geom = [x, y, w, h]
         model.maybe_recalculate_geometry_for(self)
+        aw, ah = model.get_property("actual-size")
+        if aw!=w or ah!=h:
+            log.warn("DesktopManager: updating model with new size: %sx%s", aw, ah)
+            self._models[model].geom = [x, y, aw, ah]

     def hide_window(self, model):
         if not model.get_property("iconic"):

This is what I see with this patch:

Uh-oh, our size doesn't fit window sizing constraints: 487x276 vs 562x276
Uh-oh, our size doesn't fit window sizing constraints: 487x276 vs 562x276
DesktopManager: updating model with new size: 562x276
Uh-oh, our size doesn't fit window sizing constraints: 487x276 vs 562x276
DesktopManager: updating model with new size: 562x276
Uh-oh, our size doesn't fit window sizing constraints: 487x276 vs 562x276
DesktopManager: updating model with new size: 562x276
totaam commented 11 years ago

2013-04-24 08:18:44: onlyjob commented

I've managed to reproduce the issue with patch.

I've noticed that there were no more garbage in the bottom and right side of dialog but just blackness (when incorrectly rendered). I'm not sure if this is a coincidence or somehow an effect of this patch. I tested with and without opengl.

Thank you.

totaam commented 11 years ago

2013-04-24 09:05:12: totaam commented

Damn!

A few more things I have to ask you, sorry (I believe we're getting close!):

  • Server log with: 
    XPRA_DAMAGE_DEBUG=1 xpra start ...

    so I can see if the client is requesting the correct damage size or not.

  • Client log (with -d all) around the time the window appears (same as server log you provided)
  • Does the "refresh windows" option in the xpra system tray change the appearance of the window in any way?
  • Does resizing it?
  • Does this make any difference? 
    
--- src/xpra/server.py    (revision 3132)
+++ src/xpra/server.py    (working copy)
@@ -541,7 +545,7 @@
     visible = self._desktop_manager.visible(window)
     log("resize_window to %sx%s, desktop manager set it to %sx%s, visible=%s", w, h, ww, wh, visible)
     if visible:
  • self._damage(window, 0, 0, w, h)

  • self._damage(window, 0, 0, ww, wh)

    def _process_mouse_common(self, proto, wid, pointer, modifiers): ss = self._server_sources.get(proto)

totaam commented 11 years ago

2013-04-24 09:49:08: onlyjob commented

Replying to [comment:35 totaam]:

A few more things I have to ask you, sorry (I believe we're getting close!):

No worries and thanks for squashing. :)

  • Server log with: 
    XPRA_DAMAGE_DEBUG=1 xpra start ...

    so I can see if the client is requesting the correct damage size or not.

Here it is:

2013-04-24 18:36:51,011 process non-ui packet ping
2013-04-24 18:36:51,512 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792611512
2013-04-24 18:36:51,513 process non-ui packet ping_echo
2013-04-24 18:36:51,513 ping echo client load=(1150, 490, 380), measured server latency=2
2013-04-24 18:36:55,128 will process ui packet pointer-position
2013-04-24 18:36:55,129 will process ui packet pointer-position
2013-04-24 18:36:55,131 will process ui packet pointer-position
2013-04-24 18:36:55,133 will process ui packet pointer-position
2013-04-24 18:36:55,136 damage(1355, 282, 15, 422, {}) wid=2, scheduling batching expiry for sequence 6 in 26.7 ms
2013-04-24 18:36:55,136 will process ui packet pointer-position
2013-04-24 18:36:55,137 will process ui packet pointer-position
2013-04-24 18:36:55,163 send_delayed for wid 2, batch delay is 20.6, elapsed time is 27.3 ms
2013-04-24 18:36:55,164 send_delayed_regions: to regions: 1 items, 6330 pixels
2013-04-24 18:36:55,165 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:55,165 process_damage_regions: adding pixel data (1366792615.136342, 1366792615.164533, 2, 1355, 282, 15) to queue, elapsed time: 29.1 ms
2013-04-24 18:36:55,165 make_data_packet: damage data: (2, 1355, 282, 15, 422, 'rgb24')
2013-04-24 18:36:55,166 sending damage with mmap: [(3119496L, 20256)]
2013-04-24 18:36:55,166 68 MBytes/s - 20256 bytes written to mmap in 0.3 ms
2013-04-24 18:36:55,168 process non-ui packet damage-sequence
2013-04-24 18:36:55,168 packet decoding sequence 6 for window 2 15x422 took 392 µs
2013-04-24 18:36:55,168 record_latency: took 2.3 ms round trip (2.2 just for echo), 0.0 for decoding of 6330 pixels, 48 bytes sent over the network in 1.9 ms (1.8 ms for echo)
2013-04-24 18:36:55,714 will process ui packet pointer-position
2013-04-24 18:36:55,723 will process ui packet pointer-position
2013-04-24 18:36:55,727 will process ui packet pointer-position
2013-04-24 18:36:55,730 will process ui packet pointer-position
2013-04-24 18:36:55,733 will process ui packet pointer-position
2013-04-24 18:36:55,738 will process ui packet pointer-position
2013-04-24 18:36:55,740 will process ui packet pointer-position
2013-04-24 18:36:55,742 will process ui packet pointer-position
2013-04-24 18:36:55,746 will process ui packet pointer-position
2013-04-24 18:36:55,752 will process ui packet pointer-position
2013-04-24 18:36:55,752 will process ui packet pointer-position
2013-04-24 18:36:55,754 will process ui packet pointer-position
2013-04-24 18:36:55,757 will process ui packet pointer-position
2013-04-24 18:36:55,759 will process ui packet pointer-position
2013-04-24 18:36:55,761 will process ui packet pointer-position
2013-04-24 18:36:55,763 will process ui packet pointer-position
2013-04-24 18:36:55,765 will process ui packet pointer-position
2013-04-24 18:36:55,767 will process ui packet pointer-position
2013-04-24 18:36:55,773 will process ui packet pointer-position
2013-04-24 18:36:55,773 will process ui packet pointer-position
2013-04-24 18:36:55,775 will process ui packet pointer-position
2013-04-24 18:36:55,775 will process ui packet pointer-position
2013-04-24 18:36:55,777 will process ui packet pointer-position
2013-04-24 18:36:55,781 will process ui packet pointer-position
2013-04-24 18:36:55,783 will process ui packet pointer-position
2013-04-24 18:36:55,785 will process ui packet pointer-position
2013-04-24 18:36:55,787 will process ui packet pointer-position
2013-04-24 18:36:55,789 will process ui packet pointer-position
2013-04-24 18:36:55,792 will process ui packet pointer-position
2013-04-24 18:36:55,798 damage(682, 24, 36, 36, {}) wid=2, scheduling batching expiry for sequence 7 in 20.6 ms
2013-04-24 18:36:55,798 will process ui packet pointer-position
2013-04-24 18:36:55,799 will process ui packet pointer-position
2013-04-24 18:36:55,801 will process ui packet pointer-position
2013-04-24 18:36:55,803 will process ui packet pointer-position
2013-04-24 18:36:55,806 will process ui packet pointer-position
2013-04-24 18:36:55,808 will process ui packet pointer-position
2013-04-24 18:36:55,810 will process ui packet pointer-position
2013-04-24 18:36:55,813 will process ui packet pointer-position
2013-04-24 18:36:55,815 will process ui packet pointer-position
2013-04-24 18:36:55,818 will process ui packet pointer-position
2013-04-24 18:36:55,818 send_delayed for wid 2, batch delay is 20.6, elapsed time is 21.9 ms
2013-04-24 18:36:55,819 send_delayed_regions: to regions: 1 items, 1296 pixels
2013-04-24 18:36:55,819 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:55,820 process_damage_regions: adding pixel data (1366792615.796797, 1366792615.819408, 2, 682, 24, 36) to queue, elapsed time: 23.4 ms
2013-04-24 18:36:55,820 make_data_packet: damage data: (2, 682, 24, 36, 36, 'rgb24')
2013-04-24 18:36:55,820 sending damage with mmap: [(3139752L, 3888)]
2013-04-24 18:36:55,820 16 MBytes/s - 3888 bytes written to mmap in 0.2 ms
2013-04-24 18:36:55,821 will process ui packet pointer-position
2013-04-24 18:36:55,822 process non-ui packet damage-sequence
2013-04-24 18:36:55,823 packet decoding sequence 7 for window 2 36x36 took 235 µs
2013-04-24 18:36:55,823 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 1296 pixels, 44 bytes sent over the network in 1.7 ms (1.7 ms for echo)
2013-04-24 18:36:55,826 will process ui packet pointer-position
2013-04-24 18:36:55,827 will process ui packet pointer-position
2013-04-24 18:36:55,833 will process ui packet pointer-position
2013-04-24 18:36:55,835 will process ui packet pointer-position
2013-04-24 18:36:55,840 will process ui packet pointer-position
2013-04-24 18:36:55,844 will process ui packet pointer-position
2013-04-24 18:36:55,845 will process ui packet pointer-position
2013-04-24 18:36:55,850 will process ui packet pointer-position
2013-04-24 18:36:55,852 will process ui packet pointer-position
2013-04-24 18:36:55,855 will process ui packet pointer-position
2013-04-24 18:36:55,862 will process ui packet pointer-position
2013-04-24 18:36:56,049 will process ui packet focus
2013-04-24 18:36:56,049 _focus(2,()) has_focus=0
2013-04-24 18:36:56,050 Giving focus to client
2013-04-24 18:36:56,050 ... using XSetInputFocus
2013-04-24 18:36:56,051 ... using WM_TAKE_FOCUS
2013-04-24 18:36:56,051 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x2cc3fa0 (GdkWindow at 0x2867c60)>, 1112415388L
2013-04-24 18:36:56,055 damage(70, 24, 36, 36, {}) wid=2, scheduling batching expiry for sequence 8 in 15.2 ms
2013-04-24 18:36:56,062 will process ui packet button-action
2013-04-24 18:36:56,074 send_delayed for wid 2, batch delay is 15.2, elapsed time is 18.8 ms
2013-04-24 18:36:56,075 send_delayed_regions: to regions: 1 items, 1296 pixels
2013-04-24 18:36:56,082 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:56,082 process_damage_regions: adding pixel data (1366792616.055652, 1366792616.082095, 2, 70, 24, 36) to queue, elapsed time: 27.2 ms
2013-04-24 18:36:56,083 make_data_packet: damage data: (2, 70, 24, 36, 36, 'rgb24')
2013-04-24 18:36:56,083 sending damage with mmap: [(3143640L, 3888)]
2013-04-24 18:36:56,083 8 MBytes/s - 3888 bytes written to mmap in 0.4 ms
2013-04-24 18:36:56,086 process non-ui packet damage-sequence
2013-04-24 18:36:56,086 packet decoding sequence 8 for window 2 36x36 took 392 µs
2013-04-24 18:36:56,087 record_latency: took 2.5 ms round trip (2.5 just for echo), 0.0 for decoding of 1296 pixels, 43 bytes sent over the network in 2.1 ms (2.1 ms for echo)
2013-04-24 18:36:56,090 damage(682, 24, 36, 36, {}) wid=2, scheduling batching expiry for sequence 9 in 13.1 ms
2013-04-24 18:36:56,103 send_delayed for wid 2, batch delay is 13.1, elapsed time is 17.7 ms
2013-04-24 18:36:56,104 send_delayed_regions: to regions: 1 items, 1296 pixels
2013-04-24 18:36:56,105 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:56,105 process_damage_regions: adding pixel data (1366792616.086027, 1366792616.104831, 2, 682, 24, 36) to queue, elapsed time: 19.3 ms
2013-04-24 18:36:56,105 make_data_packet: damage data: (2, 682, 24, 36, 36, 'rgb24')
2013-04-24 18:36:56,105 sending damage with mmap: [(3147528L, 3888)]
2013-04-24 18:36:56,106 13 MBytes/s - 3888 bytes written to mmap in 0.3 ms
2013-04-24 18:36:56,141 will process ui packet button-action
2013-04-24 18:36:56,143 process non-ui packet damage-sequence
2013-04-24 18:36:56,144 packet decoding sequence 9 for window 2 36x36 took 1667 µs
2013-04-24 18:36:56,144 record_latency: took 37.5 ms round trip (37.4 just for echo), 1.0 for decoding of 1296 pixels, 44 bytes sent over the network in 35.8 ms (35.8 ms for echo)
2013-04-24 18:36:56,169 will process ui packet pointer-position
2013-04-24 18:36:56,203 do_child_configure_request_event(<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2b502d0 (GdkWindow at 0x2867000)>, 'send_event': 0, 'value_mask': 64L, 'detail': 0, 'height': 232, 'width': 482, 'window': <gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 'above': None, 'y': 0, 'x': 0, 'serial': 3684L, 'border_width': 0, 'type': 23, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:36:56,203 Reconfigure on withdrawn window
2013-04-24 18:36:56,205 Found a potential client
2013-04-24 18:36:56,205 new window 0xc0047aL - 12584058
2013-04-24 18:36:56,205 CompositeHelper.__init__(<gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>,False)
2013-04-24 18:36:56,205 call_setup() adding event receiver
2013-04-24 18:36:56,206 invalidating named pixmap
2013-04-24 18:36:56,206 setup() corral_window=<gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>
2013-04-24 18:36:56,207 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 'WM_TRANSIENT_FOR', 'WINDOW'),{}) WM_TRANSIENT_FOR
2013-04-24 18:36:56,207 Missing property WM_TRANSIENT_FOR (window)
2013-04-24 18:36:56,208 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, '_NET_WM_STATE', 'ATOM'),{}) _NET_WM_STATE
2013-04-24 18:36:56,209 Missing property _NET_WM_STATE (['atom'])
2013-04-24 18:36:56,209 reading initial value for WM_HINTS
2013-04-24 18:36:56,209 Property changed on 12584058: WM_HINTS
2013-04-24 18:36:56,209 wm_hints.input = 1
2013-04-24 18:36:56,209 reading initial value for WM_NORMAL_HINTS
2013-04-24 18:36:56,210 Property changed on 12584058: WM_NORMAL_HINTS
2013-04-24 18:36:56,210 reading initial value for WM_NAME
2013-04-24 18:36:56,210 Property changed on 12584058: WM_NAME
2013-04-24 18:36:56,211 reading initial value for _NET_WM_NAME
2013-04-24 18:36:56,212 Property changed on 12584058: _NET_WM_NAME
2013-04-24 18:36:56,212 reading initial value for WM_ICON_NAME
2013-04-24 18:36:56,212 Property changed on 12584058: WM_ICON_NAME
2013-04-24 18:36:56,217 reading initial value for _NET_WM_ICON_NAME
2013-04-24 18:36:56,217 Property changed on 12584058: _NET_WM_ICON_NAME
2013-04-24 18:36:56,222 reading initial value for _NET_WM_STRUT
2013-04-24 18:36:56,223 Property changed on 12584058: _NET_WM_STRUT
2013-04-24 18:36:56,223 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, '_NET_WM_STRUT_PARTIAL', 'CARDINAL'),{}) _NET_WM_STRUT_PARTIAL
2013-04-24 18:36:56,223 Missing property _NET_WM_STRUT_PARTIAL (strut-partial)
2013-04-24 18:36:56,224 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, '_NET_WM_STRUT', 'CARDINAL'),{}) _NET_WM_STRUT
2013-04-24 18:36:56,224 Missing property _NET_WM_STRUT (strut)
2013-04-24 18:36:56,224 reading initial value for _NET_WM_STRUT_PARTIAL
2013-04-24 18:36:56,224 Property changed on 12584058: _NET_WM_STRUT_PARTIAL
2013-04-24 18:36:56,224 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, '_NET_WM_STRUT_PARTIAL', 'CARDINAL'),{}) _NET_WM_STRUT_PARTIAL
2013-04-24 18:36:56,225 Missing property _NET_WM_STRUT_PARTIAL (strut-partial)
2013-04-24 18:36:56,225 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, '_NET_WM_STRUT', 'CARDINAL'),{}) _NET_WM_STRUT
2013-04-24 18:36:56,225 Missing property _NET_WM_STRUT (strut)
2013-04-24 18:36:56,225 Property changed on 12584058: _NET_WM_ICON
2013-04-24 18:36:56,225 _NET_WM_ICON changed on 12584058, re-reading
2013-04-24 18:36:56,227 icon is now <cairo.ImageSurface object at 0x2ecb890>
2013-04-24 18:36:56,228 setup() adding to save set
2013-04-24 18:36:56,228 setup() reparenting
2013-04-24 18:36:56,228 setup() geometry
2013-04-24 18:36:56,229 setup() resizing windows to 482x232
2013-04-24 18:36:56,229 call_setup() ended
2013-04-24 18:36:56,230 Discovered new ordinary window: <WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)> (geometry=(0, 0, 482, 232))
2013-04-24 18:36:56,230 window_types=['_NET_WM_WINDOW_TYPE_DIALOG']
2013-04-24 18:36:56,231 window_types=['_NET_WM_WINDOW_TYPE_DIALOG']
2013-04-24 18:36:56,231 new_window(new-window, <WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>, 4, 0, 0, 482, 232, ('title', 'pid', 'size-hints', 'class-instance', 'icon', 'client-machine', 'transient-for', 'window-type', 'modal'), None) metadata={'size-constraints': {'minimum-size': (482, 232)}, 'window-type': ['_NET_WM_WINDOW_TYPE_DIALOG'], 'modal': False, 'title': 'GnuCash', 'class-instance': ['gnucash', 'Gnucash'], 'client-machine': 'deblab', 'pid': 4386}
2013-04-24 18:36:56,232 send_window_icon(<WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>,4) icon=<cairo.ImageSurface object at 0x2ecb890>
2013-04-24 18:36:56,232 found new window icon: 48x48, sending as png=True
2013-04-24 18:36:56,238 Property changed on 12584058: _NET_WM_ALLOWED_ACTIONS
2013-04-24 18:36:56,239 Property changed on 12584058: _NET_FRAME_EXTENTS
2013-04-24 18:36:56,239 Property changed on 12584058: _NET_WM_STATE
2013-04-24 18:36:56,241 Property changed on 12584058: WM_STATE
2013-04-24 18:36:56,241 invalidating named pixmap
2013-04-24 18:36:56,286 Property changed on 12584058: WM_NORMAL_HINTS
2013-04-24 18:36:56,287 do_child_configure_request_event(<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'send_event': 0, 'value_mask': 12L, 'detail': 0, 'height': 274, 'width': 552, 'window': <gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 'above': None, 'y': 0, 'x': 0, 'serial': 3772L, 'border_width': 0, 'type': 23, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:36:56,290 damage(682, 24, 36, 36, {}) wid=2, scheduling batching expiry for sequence 10 in 13.1 ms
2013-04-24 18:36:56,303 send_delayed for wid 2, batch delay is 13.1, elapsed time is 13.6 ms
2013-04-24 18:36:56,304 send_delayed_regions: to regions: 1 items, 1296 pixels
2013-04-24 18:36:56,305 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:56,306 process_damage_regions: adding pixel data (1366792616.289815, 1366792616.305222, 2, 682, 24, 36) to queue, elapsed time: 16.5 ms
2013-04-24 18:36:56,306 make_data_packet: damage data: (2, 682, 24, 36, 36, 'rgb24')
2013-04-24 18:36:56,306 sending damage with mmap: [(3151416L, 3888)]
2013-04-24 18:36:56,307 17 MBytes/s - 3888 bytes written to mmap in 0.2 ms
2013-04-24 18:36:56,309 process non-ui packet damage-sequence
2013-04-24 18:36:56,309 packet decoding sequence 10 for window 2 36x36 took 248 µs
2013-04-24 18:36:56,309 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 1296 pixels, 44 bytes sent over the network in 1.7 ms (1.7 ms for echo)
2013-04-24 18:36:56,361 will process ui packet map-window
2013-04-24 18:36:56,362 DesktopManager.configure_window(<WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>, 524, 489, 552, 274)
2013-04-24 18:36:56,363 _update_client_geometry: owner()=<DesktopManager object at 0x2cb8d70 (xpra+server+DesktopManager at 0x2ce0920)>
2013-04-24 18:36:56,363 _do_update_client_geometry: 482x232
2013-04-24 18:36:56,363 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,363 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,363 _do_update_client_geometry: size=(552, 274, 552, 274)
2013-04-24 18:36:56,363 Uh-oh, our size doesn't fit window sizing constraints: 482x232 vs 552x274
2013-04-24 18:36:56,364 _do_update_client_geometry: position=(0, 0)
2013-04-24 18:36:56,365 _update_client_geometry: owner()=<DesktopManager object at 0x2cb8d70 (xpra+server+DesktopManager at 0x2ce0920)>
2013-04-24 18:36:56,366 _do_update_client_geometry: 552x274
2013-04-24 18:36:56,366 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,366 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,366 _do_update_client_geometry: size=(552, 274, 552, 274)
2013-04-24 18:36:56,366 _do_update_client_geometry: position=(524, 489)
2013-04-24 18:36:56,368 damage(0, 0, 552, 274, {}) wid=4, scheduling batching expiry for sequence 1 in 11.6 ms
2013-04-24 18:36:56,369 set_client_properties updating {} with {}
2013-04-24 18:36:56,372 Property changed on 12584058: WM_STATE
2013-04-24 18:36:56,372 will process ui packet configure-window
2013-04-24 18:36:56,373 will process ui packet focus
2013-04-24 18:36:56,376 will process ui packet focus
2013-04-24 18:36:56,378 WindowModel.composite_configure_event(<CompositeHelper object at 0x2e597d0 (wimpiggy+composite+CompositeHelper at 0x26f3da0)>, <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 'send_event': 0, 'height': 274, 'width': 552, 'window': <gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 'y': 0, 'x': 0, 'serial': 3803L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:36:56,378 BaseWindowModel.composite_configure_event(<CompositeHelper object at 0x2e597d0 (wimpiggy+composite+CompositeHelper at 0x26f3da0)>,<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 'send_event': 0, 'height': 274, 'width': 552, 'window': <gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 'y': 0, 'x': 0, 'serial': 3803L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:36:56,378 will process ui packet configure-window
2013-04-24 18:36:56,379 invalidating named pixmap
2013-04-24 18:36:56,379 invalidating named pixmap
2013-04-24 18:36:56,383 send_delayed for wid 4, batch delay is 11.6, elapsed time is 14.1 ms
2013-04-24 18:36:56,383 send_delayed_regions: using full screen update 552x274 with rgb24
2013-04-24 18:36:56,383 refreshing named pixmap
2013-04-24 18:36:56,387 get_rgb_rawdata(..) pixbuf.get_from_drawable took 2 ms, visual depth=24
2013-04-24 18:36:56,388 will process ui packet configure-window
2013-04-24 18:36:56,391 process_damage_regions: adding pixel data (1366792616.36883, 1366792616.384809, 4, 0, 0, 552) to queue, elapsed time: 22.7 ms
2013-04-24 18:36:56,391 make_data_packet: damage data: (4, 0, 0, 552, 274, 'rgb24')
2013-04-24 18:36:56,393 sending damage with mmap: [(3155304L, 453744)]
2013-04-24 18:36:56,393 237 MBytes/s - 453744 bytes written to mmap in 1.8 ms
2013-04-24 18:36:56,393 will process ui packet configure-window
2013-04-24 18:36:56,395 damage(0, 0, 552, 274, {}) wid=4, scheduling batching expiry for sequence 2 in 11.6 ms
2013-04-24 18:36:56,404 WindowModel.composite_configure_event(<CompositeHelper object at 0x2e597d0 (wimpiggy+composite+CompositeHelper at 0x26f3da0)>, <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'send_event': 0, 'height': 274, 'width': 552, 'window': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'y': 489, 'x': 524, 'serial': 3832L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:36:56,404 BaseWindowModel.composite_configure_event(<CompositeHelper object at 0x2e597d0 (wimpiggy+composite+CompositeHelper at 0x26f3da0)>,<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'send_event': 0, 'height': 274, 'width': 552, 'window': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'y': 489, 'x': 524, 'serial': 3832L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:36:56,404 invalidating named pixmap
2013-04-24 18:36:56,405 invalidating named pixmap
2013-04-24 18:36:56,407 send_delayed for wid 4, batch delay is 11.6, elapsed time is 11.9 ms
2013-04-24 18:36:56,407 process non-ui packet damage-sequence
2013-04-24 18:36:56,408 packet decoding sequence 1 for window 4 552x274 took 10161 µs
2013-04-24 18:36:56,408 record_latency: took 13.9 ms round trip (13.9 just for echo), 10.0 for decoding of 151248 pixels, 49 bytes sent over the network in 3.7 ms (3.7 ms for echo)
2013-04-24 18:36:56,408 send_delayed_regions: using full screen update 552x274 with rgb24
2013-04-24 18:36:56,409 refreshing named pixmap
2013-04-24 18:36:56,412 get_rgb_rawdata(..) pixbuf.get_from_drawable took 2 ms, visual depth=24
2013-04-24 18:36:56,416 process_damage_regions: adding pixel data (1366792616.395518, 1366792616.410105, 4, 0, 0, 552) to queue, elapsed time: 21.2 ms
2013-04-24 18:36:56,421 make_data_packet: damage data: (4, 0, 0, 552, 274, 'rgb24')
2013-04-24 18:36:56,422 sending damage with mmap: [(3609048L, 453744)]
2013-04-24 18:36:56,422 271 MBytes/s - 453744 bytes written to mmap in 1.6 ms
2013-04-24 18:36:56,425 _process_configure_window([4, 524, 489, 552, 274, {'screen': 0, 'workspace': 0}]) old window geometry: (524, 489, 552, 274)
2013-04-24 18:36:56,425 DesktopManager.configure_window(<WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>, 524, 489, 552, 274)
2013-04-24 18:36:56,426 _update_client_geometry: owner()=<DesktopManager object at 0x2cb8d70 (xpra+server+DesktopManager at 0x2ce0920)>
2013-04-24 18:36:56,426 _do_update_client_geometry: 552x274
2013-04-24 18:36:56,426 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,426 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,426 _do_update_client_geometry: size=(552, 274, 552, 274)
2013-04-24 18:36:56,426 _do_update_client_geometry: position=(524, 489)
2013-04-24 18:36:56,429 set_client_properties updating {} with {'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,429 _focus(0,()) has_focus=2
2013-04-24 18:36:56,431 widget with focus: None
2013-04-24 18:36:56,431 Focus -> world window
2013-04-24 18:36:56,431 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x2e593c0 (GdkWindow at 0x28676c0)>, 1112415770L
2013-04-24 18:36:56,432 _focus(4,()) has_focus=0
2013-04-24 18:36:56,432 _process_configure_window([4, 524, 489, 552, 274, {'screen': 0, 'workspace': 0}]) old window geometry: (524, 489, 552, 274)
2013-04-24 18:36:56,432 DesktopManager.configure_window(<WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>, 524, 489, 552, 274)
2013-04-24 18:36:56,433 _update_client_geometry: owner()=<DesktopManager object at 0x2cb8d70 (xpra+server+DesktopManager at 0x2ce0920)>
2013-04-24 18:36:56,433 _do_update_client_geometry: 552x274
2013-04-24 18:36:56,433 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,433 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,433 _do_update_client_geometry: size=(552, 274, 552, 274)
2013-04-24 18:36:56,434 _do_update_client_geometry: position=(524, 489)
2013-04-24 18:36:56,434 set_client_properties updating {'screen': 0, 'workspace': 0} with {'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,435 _process_configure_window([4, 524, 489, 552, 274, {'screen': 0, 'workspace': 0}]) old window geometry: (524, 489, 552, 274)
2013-04-24 18:36:56,435 DesktopManager.configure_window(<WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>, 524, 489, 552, 274)
2013-04-24 18:36:56,435 _update_client_geometry: owner()=<DesktopManager object at 0x2cb8d70 (xpra+server+DesktopManager at 0x2ce0920)>
2013-04-24 18:36:56,435 _do_update_client_geometry: 552x274
2013-04-24 18:36:56,435 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,436 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,436 _do_update_client_geometry: size=(552, 274, 552, 274)
2013-04-24 18:36:56,436 _do_update_client_geometry: position=(524, 489)
2013-04-24 18:36:56,438 set_client_properties updating {'screen': 0, 'workspace': 0} with {'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,438 _process_configure_window([4, 524, 489, 552, 274, {'screen': 0, 'workspace': 0}]) old window geometry: (524, 489, 552, 274)
2013-04-24 18:36:56,438 DesktopManager.configure_window(<WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>, 524, 489, 552, 274)
2013-04-24 18:36:56,438 _update_client_geometry: owner()=<DesktopManager object at 0x2cb8d70 (xpra+server+DesktopManager at 0x2ce0920)>
2013-04-24 18:36:56,438 _do_update_client_geometry: 552x274
2013-04-24 18:36:56,439 _do_update_client_geometry: hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,439 _do_update_client_geometry: sanitized hints=WMSizeHints({'min_size': (552, 274), 'max_aspect_ratio': None, 'win_gravity': 1, 'resize_inc': None, 'min_aspect_ratio': None, 'base_size': None, 'min_aspect': None, 'max_size': None, 'max_aspect': None})
2013-04-24 18:36:56,439 _do_update_client_geometry: size=(552, 274, 552, 274)
2013-04-24 18:36:56,439 _do_update_client_geometry: position=(524, 489)
2013-04-24 18:36:56,440 set_client_properties updating {'screen': 0, 'workspace': 0} with {'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,441 damage(0, 0, 552, 274, {}) wid=4, scheduling batching expiry for sequence 3 in 11.6 ms
2013-04-24 18:36:56,446 damage(70, 24, 36, 36, {}) wid=2, scheduling batching expiry for sequence 11 in 11.6 ms
2013-04-24 18:36:56,446 Giving focus to client
2013-04-24 18:36:56,446 ... using XSetInputFocus
2013-04-24 18:36:56,449 ... using WM_TAKE_FOCUS
2013-04-24 18:36:56,449 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x2e59820 (GdkWindow at 0x2dea240)>, 1112415784L
2013-04-24 18:36:56,453 send_delayed for wid 4, batch delay is 11.6, elapsed time is 11.8 ms
2013-04-24 18:36:56,453 send_delayed_regions: using full screen update 552x274 with rgb24
2013-04-24 18:36:56,458 get_rgb_rawdata(..) pixbuf.get_from_drawable took 3 ms, visual depth=24
2013-04-24 18:36:56,458 process_damage_regions: adding pixel data (1366792616.441802, 1366792616.454998, 4, 0, 0, 552) to queue, elapsed time: 17.1 ms
2013-04-24 18:36:56,459 make_data_packet: damage data: (4, 0, 0, 552, 274, 'rgb24')
2013-04-24 18:36:56,462 sending damage with mmap: [(4062792L, 453744)]
2013-04-24 18:36:56,462 127 MBytes/s - 453744 bytes written to mmap in 3.4 ms
2013-04-24 18:36:56,463 send_delayed for wid 2, batch delay is 11.6, elapsed time is 17.6 ms
2013-04-24 18:36:56,464 send_delayed_regions: to regions: 1 items, 1296 pixels
2013-04-24 18:36:56,465 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:56,465 process_damage_regions: adding pixel data (1366792616.446061, 1366792616.464938, 2, 70, 24, 36) to queue, elapsed time: 19.3 ms
2013-04-24 18:36:56,465 make_data_packet: damage data: (2, 70, 24, 36, 36, 'rgb24')
2013-04-24 18:36:56,466 sending damage with mmap: [(4516536L, 3888)]
2013-04-24 18:36:56,466 15 MBytes/s - 3888 bytes written to mmap in 0.2 ms
2013-04-24 18:36:56,483 process non-ui packet damage-sequence
2013-04-24 18:36:56,483 packet decoding sequence 2 for window 4 552x274 took 57090 µs
2013-04-24 18:36:56,483 record_latency: took 60.4 ms round trip (60.3 just for echo), 57.0 for decoding of 151248 pixels, 49 bytes sent over the network in 3.3 ms (3.2 ms for echo)
2013-04-24 18:36:56,526 process non-ui packet damage-sequence
2013-04-24 18:36:56,526 packet decoding sequence 3 for window 4 552x274 took 41997 µs
2013-04-24 18:36:56,526 record_latency: took 62.6 ms round trip (62.1 just for echo), 41.0 for decoding of 151248 pixels, 49 bytes sent over the network in 20.6 ms (20.1 ms for echo)
2013-04-24 18:36:56,526 process non-ui packet damage-sequence
2013-04-24 18:36:56,526 packet decoding sequence 11 for window 2 36x36 took 42199 µs
2013-04-24 18:36:56,527 record_latency: took 60.3 ms round trip (60.2 just for echo), 42.0 for decoding of 1296 pixels, 43 bytes sent over the network in 18.1 ms (18.0 ms for echo)
2013-04-24 18:36:56,744 do_wimpiggy_child_map_event(<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2b502d0 (GdkWindow at 0x2867000)>, 'send_event': 0, 'override_redirect': 1, 'window': <gtk.gdk.Window object at 0x2e59730 (GdkWindow at 0x2dea360)>, 'serial': 4168L, 'type': 19, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:36:56,745 Discovered new override-redirect window: 0xc004f1L (tray=None)
2013-04-24 18:36:56,745 new window 0xc004f1L - 12584177
2013-04-24 18:36:56,745 CompositeHelper.__init__(<gtk.gdk.Window object at 0x2e59730 (GdkWindow at 0x2dea360)>,False)
2013-04-24 18:36:56,746 _call(True,<built-in function XGetWindowProperty>,(<gtk.gdk.Window object at 0x2e59730 (GdkWindow at 0x2dea360)>, 'WM_TRANSIENT_FOR', 'WINDOW'),{}) WM_TRANSIENT_FOR
2013-04-24 18:36:56,746 Missing property WM_TRANSIENT_FOR (window)
2013-04-24 18:36:56,747 call_setup() adding event receiver
2013-04-24 18:36:56,747 invalidating named pixmap
2013-04-24 18:36:56,748 refreshing named pixmap
2013-04-24 18:36:56,748 call_setup() ended
2013-04-24 18:36:56,749 window_types=['_NET_WM_WINDOW_TYPE_TOOLTIP']
2013-04-24 18:36:56,749 window_types=['_NET_WM_WINDOW_TYPE_TOOLTIP']
2013-04-24 18:36:56,749 new_window(new-override-redirect, <OverrideRedirectWindowModel object at 0x2e59410 (wimpiggy+window+OverrideRedirectWindowModel at 0x26f4140)>, 5, 733, 131, 290, 22, ('transient-for', 'window-type'), None) metadata={'window-type': ['_NET_WM_WINDOW_TYPE_TOOLTIP']}
2013-04-24 18:36:56,752 damage(0, 0, 290, 22, {}) wid=5, scheduling batching expiry for sequence 1 in 10.8 ms
2013-04-24 18:36:56,753 damage(733, 131, 290, 22, {}) wid=5, using existing delayed rgb24 region created 0.0ms ago
2013-04-24 18:36:56,762 send_delayed for wid 5, batch delay is 10.8, elapsed time is 10.5 ms
2013-04-24 18:36:56,762 send_delayed_regions: using full screen update 290x22 with rgb24
2013-04-24 18:36:56,763 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:56,763 process_damage_regions: adding pixel data (1366792616.752081, 1366792616.763383, 5, 0, 0, 290) to queue, elapsed time: 11.8 ms
2013-04-24 18:36:56,764 make_data_packet: damage data: (5, 0, 0, 290, 22, 'rgb24')
2013-04-24 18:36:56,764 sending damage with mmap: [(4520424L, 19184)]
2013-04-24 18:36:56,764 71 MBytes/s - 19184 bytes written to mmap in 0.3 ms
2013-04-24 18:36:56,767 process non-ui packet damage-sequence
2013-04-24 18:36:56,767 packet decoding sequence 1 for window 5 290x22 took 349 µs
2013-04-24 18:36:56,768 record_latency: took 3.0 ms round trip (2.9 just for echo), 0.0 for decoding of 6380 pixels, 45 bytes sent over the network in 2.6 ms (2.6 ms for echo)
2013-04-24 18:36:57,249 damage(72, 130, 219, 20, {}) wid=4, scheduling batching expiry for sequence 4 in 9.3 ms
2013-04-24 18:36:57,259 send_delayed for wid 4, batch delay is 9.3, elapsed time is 9.7 ms
2013-04-24 18:36:57,259 send_delayed_regions: to regions: 1 items, 4380 pixels
2013-04-24 18:36:57,260 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:57,260 process_damage_regions: adding pixel data (1366792617.249585, 1366792617.259987, 4, 72, 130, 219) to queue, elapsed time: 10.8 ms
2013-04-24 18:36:57,260 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:36:57,260 sending damage with mmap: [(4539608L, 13200)]
2013-04-24 18:36:57,261 55 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:36:57,263 process non-ui packet damage-sequence
2013-04-24 18:36:57,263 packet decoding sequence 4 for window 4 219x20 took 498 µs
2013-04-24 18:36:57,263 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 4380 pixels, 49 bytes sent over the network in 1.4 ms (1.4 ms for echo)
2013-04-24 18:36:57,438 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792617438
2013-04-24 18:36:57,669 process non-ui packet ping_echo
2013-04-24 18:36:57,670 ping echo client load=(1060, 480, 380), measured server latency=2
2013-04-24 18:36:57,670 damage(72, 130, 219, 20, {}) wid=4, scheduling batching expiry for sequence 5 in 7.7 ms
2013-04-24 18:36:57,677 send_delayed for wid 4, batch delay is 7.7, elapsed time is 8.2 ms
2013-04-24 18:36:57,677 send_delayed_regions: to regions: 1 items, 4380 pixels
2013-04-24 18:36:57,678 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:57,678 process_damage_regions: adding pixel data (1366792617.66937, 1366792617.67834, 4, 72, 130, 219) to queue, elapsed time: 9.4 ms
2013-04-24 18:36:57,679 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:36:57,679 sending damage with mmap: [(4552808L, 13200)]
2013-04-24 18:36:57,679 54 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:36:57,681 process non-ui packet damage-sequence
2013-04-24 18:36:57,681 packet decoding sequence 5 for window 4 219x20 took 190 µs
2013-04-24 18:36:57,681 record_latency: took 2.0 ms round trip (2.0 just for echo), 0.0 for decoding of 4380 pixels, 48 bytes sent over the network in 1.8 ms (1.8 ms for echo)
2013-04-24 18:36:58,452 damage(72, 130, 219, 20, {}) wid=4, scheduling batching expiry for sequence 6 in 6.5 ms
2013-04-24 18:36:58,459 send_delayed for wid 4, batch delay is 6.5, elapsed time is 6.8 ms
2013-04-24 18:36:58,459 send_delayed_regions: to regions: 1 items, 4380 pixels
2013-04-24 18:36:58,459 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:58,460 process_damage_regions: adding pixel data (1366792618.452172, 1366792618.459676, 4, 72, 130, 219) to queue, elapsed time: 8.0 ms
2013-04-24 18:36:58,460 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:36:58,460 sending damage with mmap: [(4566008L, 13200)]
2013-04-24 18:36:58,460 54 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:36:58,462 process non-ui packet damage-sequence
2013-04-24 18:36:58,462 packet decoding sequence 6 for window 4 219x20 took 190 µs
2013-04-24 18:36:58,463 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 4380 pixels, 49 bytes sent over the network in 1.7 ms (1.7 ms for echo)
2013-04-24 18:36:58,853 damage(72, 130, 219, 20, {}) wid=4, scheduling batching expiry for sequence 7 in 5.5 ms
2013-04-24 18:36:58,858 send_delayed for wid 4, batch delay is 5.5, elapsed time is 5.6 ms
2013-04-24 18:36:58,858 send_delayed_regions: to regions: 1 items, 4380 pixels
2013-04-24 18:36:58,859 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:58,859 process_damage_regions: adding pixel data (1366792618.852903, 1366792618.859306, 4, 72, 130, 219) to queue, elapsed time: 6.8 ms
2013-04-24 18:36:58,860 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:36:58,860 sending damage with mmap: [(4579208L, 13200)]
2013-04-24 18:36:58,861 27 MBytes/s - 13200 bytes written to mmap in 0.5 ms
2013-04-24 18:36:58,862 process non-ui packet damage-sequence
2013-04-24 18:36:58,863 packet decoding sequence 7 for window 4 219x20 took 230 µs
2013-04-24 18:36:58,863 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 4380 pixels, 49 bytes sent over the network in 1.7 ms (1.6 ms for echo)
2013-04-24 18:36:59,654 damage(72, 130, 219, 20, {}) wid=4, sending now with sequence 8
2013-04-24 18:36:59,655 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:36:59,655 process_damage_regions: adding pixel data (1366792619.654412, 1366792619.655333, 4, 72, 130, 219) to queue, elapsed time: 1.4 ms
2013-04-24 18:36:59,656 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:36:59,656 sending damage with mmap: [(4592408L, 13200)]
2013-04-24 18:36:59,656 51 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:36:59,658 process non-ui packet damage-sequence
2013-04-24 18:36:59,658 packet decoding sequence 8 for window 4 219x20 took 197 µs
2013-04-24 18:36:59,658 record_latency: took 1.8 ms round trip (1.8 just for echo), 0.0 for decoding of 4380 pixels, 48 bytes sent over the network in 1.6 ms (1.6 ms for echo)
2013-04-24 18:37:00,055 damage(72, 130, 219, 20, {}) wid=4, sending now with sequence 9
2013-04-24 18:37:00,056 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:37:00,056 process_damage_regions: adding pixel data (1366792620.055366, 1366792620.05627, 4, 72, 130, 219) to queue, elapsed time: 1.4 ms
2013-04-24 18:37:00,057 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:37:00,057 sending damage with mmap: [(4605608L, 13200)]
2013-04-24 18:37:00,057 52 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:37:00,059 process non-ui packet damage-sequence
2013-04-24 18:37:00,060 packet decoding sequence 9 for window 4 219x20 took 241 µs
2013-04-24 18:37:00,060 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 4380 pixels, 49 bytes sent over the network in 1.6 ms (1.6 ms for echo)
2013-04-24 18:37:00,407 will process ui packet pointer-position
2013-04-24 18:37:00,410 WindowModel.composite_configure_event(<CompositeHelper object at 0x2d444b0 (wimpiggy+composite+CompositeHelper at 0x26f5460)>, <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'send_event': 0, 'height': 748, 'width': 1374, 'window': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'y': 57, 'x': 2, 'serial': 4260L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:37:00,411 BaseWindowModel.composite_configure_event(<CompositeHelper object at 0x2d444b0 (wimpiggy+composite+CompositeHelper at 0x26f5460)>,<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'send_event': 0, 'height': 748, 'width': 1374, 'window': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'y': 57, 'x': 2, 'serial': 4260L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:37:00,411 invalidating named pixmap
2013-04-24 18:37:00,411 will process ui packet pointer-position
2013-04-24 18:37:00,412 invalidating named pixmap
2013-04-24 18:37:00,412 will process ui packet pointer-position
2013-04-24 18:37:00,414 will process ui packet pointer-position
2013-04-24 18:37:00,413 damage(4, 4, 282, 15, {}) wid=5, scheduling batching expiry for sequence 2 in 7.3 ms
2013-04-24 18:37:00,417 will process ui packet pointer-position
2013-04-24 18:37:00,418 will process ui packet pointer-position
2013-04-24 18:37:00,420 will process ui packet pointer-position
2013-04-24 18:37:00,422 will process ui packet pointer-position
2013-04-24 18:37:00,423 will process ui packet pointer-position
2013-04-24 18:37:00,423 send_delayed for wid 5, batch delay is 7.3, elapsed time is 10.2 ms
2013-04-24 18:37:00,424 send_delayed_regions: using full screen update 290x22 with rgb24
2013-04-24 18:37:00,425 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:37:00,425 will process ui packet pointer-position
2013-04-24 18:37:00,426 process_damage_regions: adding pixel data (1366792620.413433, 1366792620.424915, 5, 0, 0, 290) to queue, elapsed time: 12.8 ms
2013-04-24 18:37:00,427 will process ui packet pointer-position
2013-04-24 18:37:00,428 make_data_packet: damage data: (5, 0, 0, 290, 22, 'rgb24')
2013-04-24 18:37:00,428 sending damage with mmap: [(4618808L, 19184)]
2013-04-24 18:37:00,428 68 MBytes/s - 19184 bytes written to mmap in 0.3 ms
2013-04-24 18:37:00,430 will process ui packet pointer-position
2013-04-24 18:37:00,432 process non-ui packet damage-sequence
2013-04-24 18:37:00,432 packet decoding sequence 2 for window 5 290x22 took 492 µs
2013-04-24 18:37:00,432 record_latency: took 3.6 ms round trip (3.6 just for echo), 0.0 for decoding of 6380 pixels, 45 bytes sent over the network in 3.1 ms (3.1 ms for echo)
2013-04-24 18:37:00,433 will process ui packet pointer-position
2013-04-24 18:37:00,435 will process ui packet pointer-position
2013-04-24 18:37:00,437 will process ui packet pointer-position
2013-04-24 18:37:00,438 will process ui packet pointer-position
2013-04-24 18:37:00,436 damage(4, 4, 282, 15, {}) wid=5, scheduling batching expiry for sequence 3 in 7.3 ms
2013-04-24 18:37:00,438 will process ui packet pointer-position
2013-04-24 18:37:00,441 will process ui packet pointer-position
2013-04-24 18:37:00,442 will process ui packet pointer-position
2013-04-24 18:37:00,444 cancel_damage() wid=5, dropping delayed region (1366792620.436742, <OverrideRedirectWindowModel object at 0x2e59410 (wimpiggy+window+OverrideRedirectWindowModel at 0x26f4140)>, <GdkRegion at 0x2dec630>, 'rgb24', {}) and all sequences up to 3
2013-04-24 18:37:00,445 encoding_totals for wid=5 with primary encoding=rgb24 : {'mmap': [2, 12760]}
2013-04-24 18:37:00,445 do_unmanaged(False) damage_forward_handle=88, composite=<CompositeHelper object at 0x2e59c30 (wimpiggy+composite+CompositeHelper at 0x26f5760)>
2013-04-24 18:37:00,446 invalidating named pixmap
2013-04-24 18:37:00,447 invalidating named pixmap
2013-04-24 18:37:00,447 invalidating named pixmap
2013-04-24 18:37:00,447 will process ui packet pointer-position
2013-04-24 18:37:00,449 will process ui packet pointer-position
2013-04-24 18:37:00,450 will process ui packet pointer-position
2013-04-24 18:37:00,450 damage(682, 24, 36, 36, {}) wid=2, scheduling batching expiry for sequence 12 in 11.0 ms
2013-04-24 18:37:00,453 will process ui packet pointer-position
2013-04-24 18:37:00,456 will process ui packet pointer-position
2013-04-24 18:37:00,456 will process ui packet pointer-position
2013-04-24 18:37:00,456 will process ui packet pointer-position
2013-04-24 18:37:00,460 send_delayed for wid 2, batch delay is 11.0, elapsed time is 11.3 ms
2013-04-24 18:37:00,460 send_delayed_regions: to regions: 1 items, 1296 pixels
2013-04-24 18:37:00,461 refreshing named pixmap
2013-04-24 18:37:00,462 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:37:00,462 process_damage_regions: adding pixel data (1366792620.449269, 1366792620.46229, 2, 682, 24, 36) to queue, elapsed time: 13.5 ms
2013-04-24 18:37:00,463 make_data_packet: damage data: (2, 682, 24, 36, 36, 'rgb24')
2013-04-24 18:37:00,463 sending damage with mmap: [(4637992L, 3888)]
2013-04-24 18:37:00,463 15 MBytes/s - 3888 bytes written to mmap in 0.2 ms
2013-04-24 18:37:00,466 will process ui packet pointer-position
2013-04-24 18:37:00,467 will process ui packet pointer-position
2013-04-24 18:37:00,468 will process ui packet pointer-position
2013-04-24 18:37:00,469 process non-ui packet damage-sequence
2013-04-24 18:37:00,469 packet decoding sequence 12 for window 2 36x36 took 201 µs
2013-04-24 18:37:00,469 record_latency: took 5.3 ms round trip (5.3 just for echo), 0.0 for decoding of 1296 pixels, 44 bytes sent over the network in 5.1 ms (5.1 ms for echo)
2013-04-24 18:37:00,472 will process ui packet pointer-position
2013-04-24 18:37:00,472 will process ui packet pointer-position
2013-04-24 18:37:00,473 will process ui packet pointer-position
2013-04-24 18:37:00,473 will process ui packet pointer-position
2013-04-24 18:37:00,473 will process ui packet pointer-position
2013-04-24 18:37:00,475 will process ui packet pointer-position
2013-04-24 18:37:00,477 will process ui packet pointer-position
2013-04-24 18:37:00,478 will process ui packet pointer-position
2013-04-24 18:37:00,480 will process ui packet pointer-position
2013-04-24 18:37:00,482 will process ui packet pointer-position
2013-04-24 18:37:00,484 will process ui packet pointer-position
2013-04-24 18:37:00,486 will process ui packet pointer-position
2013-04-24 18:37:00,488 will process ui packet pointer-position
2013-04-24 18:37:00,491 will process ui packet pointer-position
2013-04-24 18:37:00,494 will process ui packet pointer-position
2013-04-24 18:37:00,495 will process ui packet pointer-position
2013-04-24 18:37:00,496 will process ui packet pointer-position
2013-04-24 18:37:00,498 will process ui packet pointer-position
2013-04-24 18:37:00,498 send_cursor(): default cursor - clearing it
2013-04-24 18:37:00,500 will process ui packet pointer-position
2013-04-24 18:37:00,502 will process ui packet pointer-position
2013-04-24 18:37:00,504 will process ui packet pointer-position
2013-04-24 18:37:00,506 will process ui packet pointer-position
2013-04-24 18:37:00,508 will process ui packet pointer-position
2013-04-24 18:37:00,510 will process ui packet pointer-position
2013-04-24 18:37:00,512 will process ui packet pointer-position
2013-04-24 18:37:00,514 will process ui packet pointer-position
2013-04-24 18:37:00,516 will process ui packet pointer-position
2013-04-24 18:37:00,518 will process ui packet pointer-position
2013-04-24 18:37:00,520 will process ui packet pointer-position
2013-04-24 18:37:00,522 will process ui packet pointer-position
2013-04-24 18:37:00,524 will process ui packet pointer-position
2013-04-24 18:37:00,526 will process ui packet pointer-position
2013-04-24 18:37:00,532 will process ui packet pointer-position
2013-04-24 18:37:00,534 will process ui packet pointer-position
2013-04-24 18:37:00,535 WindowModel.composite_configure_event(<CompositeHelper object at 0x2e597d0 (wimpiggy+composite+CompositeHelper at 0x26f3da0)>, <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'send_event': 0, 'height': 274, 'width': 552, 'window': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'y': 489, 'x': 524, 'serial': 4574L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:37:00,536 BaseWindowModel.composite_configure_event(<CompositeHelper object at 0x2e597d0 (wimpiggy+composite+CompositeHelper at 0x26f3da0)>,<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'send_event': 0, 'height': 274, 'width': 552, 'window': <gtk.gdk.Window object at 0x2e595a0 (GdkWindow at 0x2dea000)>, 'y': 489, 'x': 524, 'serial': 4574L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:37:00,536 invalidating named pixmap
2013-04-24 18:37:00,536 will process ui packet pointer-position
2013-04-24 18:37:00,537 invalidating named pixmap
2013-04-24 18:37:00,538 will process ui packet pointer-position
2013-04-24 18:37:00,540 will process ui packet pointer-position
2013-04-24 18:37:00,543 will process ui packet pointer-position
2013-04-24 18:37:00,544 will process ui packet pointer-position
2013-04-24 18:37:00,546 will process ui packet pointer-position
2013-04-24 18:37:00,548 will process ui packet pointer-position
2013-04-24 18:37:00,550 will process ui packet pointer-position
2013-04-24 18:37:00,552 will process ui packet pointer-position
2013-04-24 18:37:00,554 will process ui packet pointer-position
2013-04-24 18:37:00,557 will process ui packet pointer-position
2013-04-24 18:37:00,560 will process ui packet pointer-position
2013-04-24 18:37:00,560 will process ui packet pointer-position
2013-04-24 18:37:00,564 will process ui packet pointer-position
2013-04-24 18:37:00,565 will process ui packet pointer-position
2013-04-24 18:37:00,566 will process ui packet pointer-position
2013-04-24 18:37:00,568 will process ui packet pointer-position
2013-04-24 18:37:00,570 will process ui packet pointer-position
2013-04-24 18:37:00,573 will process ui packet pointer-position
2013-04-24 18:37:00,574 will process ui packet pointer-position
2013-04-24 18:37:00,576 will process ui packet pointer-position
2013-04-24 18:37:00,579 will process ui packet pointer-position
2013-04-24 18:37:00,580 will process ui packet pointer-position
2013-04-24 18:37:00,582 will process ui packet pointer-position
2013-04-24 18:37:00,584 will process ui packet pointer-position
2013-04-24 18:37:00,586 will process ui packet pointer-position
2013-04-24 18:37:00,589 will process ui packet pointer-position
2013-04-24 18:37:00,590 will process ui packet pointer-position
2013-04-24 18:37:00,592 will process ui packet pointer-position
2013-04-24 18:37:00,594 will process ui packet pointer-position
2013-04-24 18:37:00,596 will process ui packet pointer-position
2013-04-24 18:37:00,598 will process ui packet pointer-position
2013-04-24 18:37:00,600 will process ui packet pointer-position
2013-04-24 18:37:00,602 will process ui packet pointer-position
2013-04-24 18:37:00,603 send_cursor(): default cursor - clearing it
2013-04-24 18:37:00,605 will process ui packet pointer-position
2013-04-24 18:37:00,607 will process ui packet pointer-position
2013-04-24 18:37:00,607 WindowModel.composite_configure_event(<CompositeHelper object at 0x2d444b0 (wimpiggy+composite+CompositeHelper at 0x26f5460)>, <AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'send_event': 0, 'height': 748, 'width': 1374, 'window': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'y': 57, 'x': 2, 'serial': 4789L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:37:00,607 BaseWindowModel.composite_configure_event(<CompositeHelper object at 0x2d444b0 (wimpiggy+composite+CompositeHelper at 0x26f5460)>,<AdHocStruct object, contents: {'delivered_to': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'send_event': 0, 'height': 748, 'width': 1374, 'window': <gtk.gdk.Window object at 0x2d445f0 (GdkWindow at 0x2867d80)>, 'y': 57, 'x': 2, 'serial': 4789L, 'border_width': 0, 'type': 22, 'display': <gtk.gdk.Display object at 0x2a080f0 (GdkDisplayX11 at 0x2a8f220)>}>)
2013-04-24 18:37:00,608 invalidating named pixmap
2013-04-24 18:37:00,608 will process ui packet pointer-position
2013-04-24 18:37:00,608 invalidating named pixmap
2013-04-24 18:37:00,611 will process ui packet pointer-position
2013-04-24 18:37:00,612 will process ui packet pointer-position
2013-04-24 18:37:00,618 will process ui packet pointer-position
2013-04-24 18:37:00,856 damage(72, 130, 219, 20, {}) wid=4, sending now with sequence 10
2013-04-24 18:37:00,857 refreshing named pixmap
2013-04-24 18:37:00,858 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:37:00,858 process_damage_regions: adding pixel data (1366792620.856333, 1366792620.858141, 4, 72, 130, 219) to queue, elapsed time: 2.3 ms
2013-04-24 18:37:00,858 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:37:00,859 sending damage with mmap: [(4641880L, 13200)]
2013-04-24 18:37:00,859 54 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:37:00,861 process non-ui packet damage-sequence
2013-04-24 18:37:00,861 packet decoding sequence 10 for window 4 219x20 took 234 µs
2013-04-24 18:37:00,861 record_latency: took 1.9 ms round trip (1.9 just for echo), 0.0 for decoding of 4380 pixels, 49 bytes sent over the network in 1.7 ms (1.7 ms for echo)
2013-04-24 18:37:01,012 process non-ui packet ping
2013-04-24 18:37:01,257 damage(72, 130, 219, 20, {}) wid=4, sending now with sequence 11
2013-04-24 18:37:01,258 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:37:01,258 process_damage_regions: adding pixel data (1366792621.256877, 1366792621.257807, 4, 72, 130, 219) to queue, elapsed time: 1.4 ms
2013-04-24 18:37:01,258 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:37:01,259 sending damage with mmap: [(4655080L, 13200)]
2013-04-24 18:37:01,259 55 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:37:01,261 process non-ui packet damage-sequence
2013-04-24 18:37:01,262 packet decoding sequence 11 for window 4 219x20 took 220 µs
2013-04-24 18:37:01,262 record_latency: took 2.7 ms round trip (2.7 just for echo), 0.0 for decoding of 4380 pixels, 49 bytes sent over the network in 2.5 ms (2.5 ms for echo)
2013-04-24 18:37:01,513 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792621512
2013-04-24 18:37:01,514 process non-ui packet ping_echo
2013-04-24 18:37:01,514 ping echo client load=(980, 470, 380), measured server latency=3
2013-04-24 18:37:01,927 will process ui packet focus
2013-04-24 18:37:01,928 _focus(0,()) has_focus=4
2013-04-24 18:37:01,928 widget with focus: None
2013-04-24 18:37:01,928 Focus -> world window
2013-04-24 18:37:01,929 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x2e59c30 (GdkWindow at 0x28676c0)>, 1112421267L
2013-04-24 18:37:01,931 damage(72, 130, 219, 20, {}) wid=4, sending now with sequence 12
2013-04-24 18:37:01,933 get_rgb_rawdata(..) pixbuf.get_from_drawable took 0 ms, visual depth=24
2013-04-24 18:37:01,934 process_damage_regions: adding pixel data (1366792621.931634, 1366792621.933232, 4, 72, 130, 219) to queue, elapsed time: 2.5 ms
2013-04-24 18:37:01,934 make_data_packet: damage data: (4, 72, 130, 219, 20, 'rgb24')
2013-04-24 18:37:01,934 sending damage with mmap: [(4668280L, 13200)]
2013-04-24 18:37:01,934 54 MBytes/s - 13200 bytes written to mmap in 0.2 ms
2013-04-24 18:37:01,936 process non-ui packet damage-sequence
2013-04-24 18:37:01,936 packet decoding sequence 12 for window 4 219x20 took 241 µs
2013-04-24 18:37:01,937 record_latency: took 1.8 ms round trip (1.8 just for echo), 0.0 for decoding of 4380 pixels, 48 bytes sent over the network in 1.6 ms (1.5 ms for echo)
2013-04-24 18:37:07,444 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792627444
2013-04-24 18:37:07,445 process non-ui packet ping_echo
2013-04-24 18:37:07,445 ping echo client load=(900, 470, 380), measured server latency=3
2013-04-24 18:37:11,019 process non-ui packet ping
2013-04-24 18:37:11,520 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792631520
2013-04-24 18:37:11,521 process non-ui packet ping_echo
2013-04-24 18:37:11,522 ping echo client load=(910, 480, 380), measured server latency=3
2013-04-24 18:37:17,450 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792637449
2013-04-24 18:37:17,451 process non-ui packet ping_echo
2013-04-24 18:37:17,451 ping echo client load=(830, 470, 380), measured server latency=3
2013-04-24 18:37:21,027 process non-ui packet ping
2013-04-24 18:37:21,528 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792641528
2013-04-24 18:37:21,529 process non-ui packet ping_echo
2013-04-24 18:37:21,529 ping echo client load=(850, 480, 380), measured server latency=3
2013-04-24 18:37:27,454 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792647453
2013-04-24 18:37:27,506 process non-ui packet ping_echo
2013-04-24 18:37:27,506 ping echo client load=(860, 490, 380), measured server latency=3
2013-04-24 18:37:31,036 process non-ui packet ping
2013-04-24 18:37:31,537 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792651537
2013-04-24 18:37:31,538 process non-ui packet ping_echo
2013-04-24 18:37:31,538 ping echo client load=(790, 480, 380), measured server latency=3
2013-04-24 18:37:37,458 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792657457
2013-04-24 18:37:37,459 process non-ui packet ping_echo
2013-04-24 18:37:37,459 ping echo client load=(730, 470, 380), measured server latency=3
2013-04-24 18:37:41,045 process non-ui packet ping
2013-04-24 18:37:41,546 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792661545
2013-04-24 18:37:41,547 process non-ui packet ping_echo
2013-04-24 18:37:41,547 ping echo client load=(670, 460, 380), measured server latency=3
2013-04-24 18:37:47,458 sending ping to Protocol(SocketConnection(/home/hawk/.xpra/deblab-11)) with time=1366792667458
2013-04-24 18:37:47,459 process non-ui packet ping_echo
2013-04-24 18:37:47,459 ping echo client load=(620, 450, 380), measured server latency=3
  • Client log (with -d all) around the time the window appears (same as server log you provided)

I didn't use "XPRA_DAMAGE_DEBUG=1" on client so the following is just with "-d all":

2013-04-24 18:36:56,045 _focus_change((<ClientWindow object at 0x34c79b0 (xpra+client_window+ClientWindow at 0x3447dd0)>, <GParamBoolean 'has-toplevel-focus'>))      
2013-04-24 18:36:56,046 update_focus(2,True) _focused=None                                                                                                            
2013-04-24 18:36:56,064 property_changed: _NET_WM_USER_TIME                                                                                                           
2013-04-24 18:36:56,234 window types=('_NET_WM_WINDOW_TYPE_DIALOG',)                                                                                                  
2013-04-24 18:36:56,234 setting window type to _NET_WM_WINDOW_TYPE_DIALOG - <enum GDK_WINDOW_TYPE_HINT_DIALOG of type GdkWindowTypeHint>                              
2013-04-24 18:36:56,236 _process_window_icon([4, 48, 48, 'png'],3430 bytes)                                                                                           
2013-04-24 18:36:56,249 property_changed: _NET_WM_NAME                                                                                                                
2013-04-24 18:36:56,249 property_changed: WM_NAME                                                                                                                     
2013-04-24 18:36:56,249 property_changed: _NET_WM_ICON_NAME                                                                                                           
2013-04-24 18:36:56,249 property_changed: WM_ICON_NAME                                                                                                                
2013-04-24 18:36:56,249 property_changed: WM_CLASS                                                                                                                    
2013-04-24 18:36:56,250 property_changed: WM_PROTOCOLS                                                                                                                
2013-04-24 18:36:56,250 property_changed: WM_NORMAL_HINTS                                                                                                             
2013-04-24 18:36:56,250 property_changed: WM_CLIENT_MACHINE                                                                                                           
2013-04-24 18:36:56,250 property_changed: WM_LOCALE_NAME                                                                                                              
2013-04-24 18:36:56,250 property_changed: _NET_WM_PID                                                                                                                 
2013-04-24 18:36:56,251 property_changed: WM_CLIENT_LEADER                                                                                                            
2013-04-24 18:36:56,251 property_changed: _NET_WM_USER_TIME_WINDOW                                                                                                    
2013-04-24 18:36:56,251 property_changed: _NET_WM_USER_TIME                                                                                                           
2013-04-24 18:36:56,251 property_changed: _NET_WM_WINDOW_TYPE                                                                                                         
2013-04-24 18:36:56,251 property_changed: _NET_WM_SYNC_REQUEST_COUNTER                                                                                                
2013-04-24 18:36:56,251 property_changed: _NET_WM_ICON                                                                                                                
2013-04-24 18:36:56,252 property_changed: WM_NORMAL_HINTS                                                                                                             
2013-04-24 18:36:56,252 property_changed: _NET_WM_WINDOW_TYPE                                                                                                         
2013-04-24 18:36:56,252 property_changed: WM_HINTS                                                                                                                    
2013-04-24 18:36:56,252 property_changed: _NET_WM_ICON                                                                                                                
2013-04-24 18:36:56,252 property_changed: WM_HINTS                                                                                                                    
2013-04-24 18:36:56,310 property_changed: _NET_WM_NAME                                                                                                                
2013-04-24 18:36:56,310 property_changed: WM_NAME                                                                                                                     
2013-04-24 18:36:56,311 property_changed: _NET_WM_ICON_NAME                                                                                                           
2013-04-24 18:36:56,311 property_changed: WM_ICON_NAME                                                                                                                
2013-04-24 18:36:56,311 property_changed: WM_NORMAL_HINTS                                                                                                             
2013-04-24 18:36:56,314 property_changed: _KDE_NET_WM_USER_CREATION_TIME                                                                                              
2013-04-24 18:36:56,346 property_changed: _NET_WM_STATE                                                                                                               
2013-04-24 18:36:56,346 Got map event: <gtk.gdk.Event at 0x352ee18: GDK_MAP>                                                                                          
2013-04-24 18:36:56,360 set_workspace() workspace=-1                                                                                                                  
2013-04-24 18:36:56,360 map-window for wid=4 with client props={}                                                                                                     
2013-04-24 18:36:56,361 property_changed: WM_STATE                                                                                                                    
2013-04-24 18:36:56,361 property_changed: _NET_FRAME_EXTENTS                                                                                                          
2013-04-24 18:36:56,361 property_changed: _KDE_NET_WM_FRAME_STRUT                                                                                                     
2013-04-24 18:36:56,363 property_changed: _NET_WM_DESKTOP                                                                                                             
2013-04-24 18:36:56,368 xget_u32_property(<gtk.gdk.Window object at 0x34dd0a0 (GdkWindow at 0x2e85900)>, _NET_WM_DESKTOP)=0                                           
2013-04-24 18:36:56,369 do_get_workspace() found value=0 from <gtk.gdk.Window object at 0x34dd0a0 (GdkWindow at 0x2e85900)> / _NET_WM_DESKTOP                         
2013-04-24 18:36:56,369 configure-window for wid=4 with client props={'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,370 property_changed: _KDE_NET_WM_TAB_GROUP
2013-04-24 18:36:56,370 property_changed: _KDE_NET_WM_TAB_GROUP
2013-04-24 18:36:56,370 property_changed: _NET_WM_ALLOWED_ACTIONS
2013-04-24 18:36:56,371 property_changed: _NET_WM_STATE
2013-04-24 18:36:56,371 _focus_change((<ClientWindow object at 0x34c79b0 (xpra+client_window+ClientWindow at 0x3447dd0)>, <GParamBoolean 'has-toplevel-focus'>))
2013-04-24 18:36:56,371 update_focus(2,False) _focused=2
2013-04-24 18:36:56,373 _focus_change((<ClientWindow object at 0x34e7d20 (xpra+client_window+ClientWindow at 0x3587290)>, <GParamBoolean 'has-toplevel-focus'>))
2013-04-24 18:36:56,373 update_focus(4,True) _focused=None
2013-04-24 18:36:56,375 Got configure event: <gtk.gdk.Event at 0x352ee18: GDK_CONFIGURE x=524, y=489, width=552, height=274>
2013-04-24 18:36:56,376 xget_u32_property(<gtk.gdk.Window object at 0x34dd0f0 (GdkWindow at 0x2e85900)>, _NET_WM_DESKTOP)=0
2013-04-24 18:36:56,377 do_get_workspace() found value=0 from <gtk.gdk.Window object at 0x34dd0f0 (GdkWindow at 0x2e85900)> / _NET_WM_DESKTOP
2013-04-24 18:36:56,377 configure-window for wid=4 with client props={'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,378 Got configure event: <gtk.gdk.Event at 0x352ee18: GDK_CONFIGURE x=524, y=489, width=552, height=274>
2013-04-24 18:36:56,385 xget_u32_property(<gtk.gdk.Window object at 0x34dd0f0 (GdkWindow at 0x2e85900)>, _NET_WM_DESKTOP)=0
2013-04-24 18:36:56,385 do_get_workspace() found value=0 from <gtk.gdk.Window object at 0x34dd0f0 (GdkWindow at 0x2e85900)> / _NET_WM_DESKTOP
2013-04-24 18:36:56,385 configure-window for wid=4 with client props={'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,386 property_changed: WM_HINTS
2013-04-24 18:36:56,386 Got configure event: <gtk.gdk.Event at 0x352ee18: GDK_CONFIGURE x=524, y=489, width=552, height=274>
2013-04-24 18:36:56,391 xget_u32_property(<gtk.gdk.Window object at 0x34dd0f0 (GdkWindow at 0x2e85900)>, _NET_WM_DESKTOP)=0
2013-04-24 18:36:56,392 do_get_workspace() found value=0 from <gtk.gdk.Window object at 0x34dd0f0 (GdkWindow at 0x2e85900)> / _NET_WM_DESKTOP
2013-04-24 18:36:56,392 configure-window for wid=4 with client props={'screen': 0, 'workspace': 0}
2013-04-24 18:36:56,394 _focus_change(())
2013-04-24 18:36:56,395 update_focus(4,True) _focused=4
2013-04-24 18:36:56,750 window types=('_NET_WM_WINDOW_TYPE_TOOLTIP',)
2013-04-24 18:36:56,751 setting window type to _NET_WM_WINDOW_TYPE_TOOLTIP - <enum GDK_WINDOW_TYPE_HINT_TOOLTIP of type GdkWindowTypeHint>
2013-04-24 18:36:56,833 property_changed: _NET_WM_NAME
2013-04-24 18:36:56,833 property_changed: WM_NAME
2013-04-24 18:36:56,833 property_changed: _NET_WM_ICON_NAME
2013-04-24 18:36:56,834 property_changed: WM_ICON_NAME
2013-04-24 18:36:56,834 property_changed: WM_CLASS
2013-04-24 18:36:56,834 property_changed: WM_PROTOCOLS
2013-04-24 18:36:56,834 property_changed: WM_NORMAL_HINTS
2013-04-24 18:36:56,834 property_changed: WM_CLIENT_MACHINE
2013-04-24 18:36:56,834 property_changed: WM_LOCALE_NAME
2013-04-24 18:36:56,835 property_changed: _NET_WM_PID
2013-04-24 18:36:56,835 property_changed: WM_CLIENT_LEADER
2013-04-24 18:36:56,835 property_changed: _NET_WM_USER_TIME_WINDOW
2013-04-24 18:36:56,835 property_changed: _NET_WM_USER_TIME
2013-04-24 18:36:56,835 property_changed: _NET_WM_WINDOW_TYPE
2013-04-24 18:36:56,836 property_changed: _NET_WM_SYNC_REQUEST_COUNTER
2013-04-24 18:36:56,836 property_changed: WM_NORMAL_HINTS
2013-04-24 18:36:56,836 Got configure event: <gtk.gdk.Event at 0x352ee18: GDK_CONFIGURE x=733, y=131, width=290, height=22>
2013-04-24 18:36:56,836 property_changed: _NET_WM_WINDOW_TYPE
2013-04-24 18:36:56,836 property_changed: WM_HINTS
2013-04-24 18:36:56,836 Got map event: <gtk.gdk.Event at 0x352ee18: GDK_MAP>
2013-04-24 18:36:56,837 _focus_change(())
2013-04-24 18:36:56,837 update_focus(5,False) _focused=4
2013-04-24 18:37:00,445 <class 'xpra.window_backing.PixmapBacking'>.close() video_decoder=None
2013-04-24 18:37:00,445 group leader=None
2013-04-24 18:37:00,602 setting new cursor: xterm=<enum GDK_XTERM of type GdkCursorType>
2013-04-24 18:37:01,011 average server latency=3.3, using max wait 1.01s
2013-04-24 18:37:01,013 ping echo server load=(980, 470, 380), measured client latency=232ms
2013-04-24 18:37:01,924 _focus_change((<ClientWindow object at 0x34e7d20 (xpra+client_window+ClientWindow at 0x3587290)>, <GParamBoolean 'has-toplevel-focus'>))
2013-04-24 18:37:01,925 update_focus(4,False) _focused=4
  • Does the "refresh windows" option in the xpra system tray change the appearance of the window in any way?

No.

  • Does resizing it?

Yes, resizing helps.

  • Does this make any difference? 
    
--- src/xpra/server.py  (revision 3132)
+++ src/xpra/server.py  (working copy)
@@ -541,7 +545,7 @@
     visible = self._desktop_manager.visible(window)
     log("resize_window to %sx%s, desktop manager set it to %sx%s, visible=%s", w, h, ww, wh, visible)
     if visible:
  • self._damage(window, 0, 0, w, h)

  • self._damage(window, 0, 0, ww, wh)

    def _process_mouse_common(self, proto, wid, pointer, modifiers): ss = self._server_sources.get(proto)

Unfortunately no. By the way logs are taken with this patch applied.

totaam commented 11 years ago

2013-04-24 10:52:37: totaam commented

OK, from the server log:

new_window(new-window, \
    <WindowModel object at 0x2e59370 (wimpiggy+window+WindowModel at 0x26f4ce0)>, \
    4, 0, 0, 482, 232, \
    ('title', 'pid', 'size-hints', 'class-instance', 'icon', 'client-machine', 'transient-for', 'window-type', 'modal'), \
    None) \
    metadata={'size-constraints': {'minimum-size': (482, 232)}, 'window-type': ['_NET_WM_WINDOW_TYPE_DIALOG'], \
    'modal': False, 'title': 'GnuCash', 'class-instance': ['gnucash', 'Gnucash'], \
    'client-machine': 'deblab', 'pid': 4386}
damage(0, 0, 552, 274, {}) wid=4, scheduling batching expiry for sequence 1 in 11.6 ms
make_data_packet: damage data: (4, 0, 0, 552, 274, 'rgb24')
damage(0, 0, 552, 274, {}) wid=4, scheduling batching expiry for sequence 2 in 11.6 ms
make_data_packet: damage data: (4, 0, 0, 552, 274, 'rgb24')
damage(0, 0, 552, 274, {}) wid=4, scheduling batching expiry for sequence 3 in 11.6 ms
make_data_packet: damage data: (4, 0, 0, 552, 274, 'rgb24')

Followed by a number of smaller updates on that same window (looks like a field or drop down got activated):

damage(72, 130, 219, 20, {}) wid=4, sending now with sequence 11

So basically, it looks like we're always sending the correct size for the "full window" damage. (and I think those patches above make sense to ensure that we do - though they may be redundant with the proper fix, once that is found)

[[BR]]

So, onto the client log... which is missing the one call I wanted to see: the first time this dialog window is mapped. But not to worry, it must be created with the smaller size we send with the "new-window" packet, and we end up with a small backing, then as we update it with pixels from the bigger regions we get from the server, the extra pixels get discarded. When we try to paint, the regions that have been chopped off are "undefined". The fact that resizing helps to confirm that: when we resize, we do re-initialize the window backing size.

[[BR]]

The solution is not simple unfortunately: we have 2 different entities that can change the window size:

  • the application itself
  • the client side window manager Each time one does resize, we have to send the updated size to the other end... and deciding which one is right is non-trivial! I think the problem here is that we get the "correct" size from the application after the window has been created, but often before the client has replied with its "configure" event and the size it actually uses..

Here's a hacked patch which tries to force the client to use the "better" size - does it help?:

--- src/xpra/server.py    (revision 3132)
+++ src/xpra/server.py    (working copy)
@@ -80,12 +80,20 @@

     def configure_window(self, model, x, y, w, h):
         log("DesktopManager.configure_window(%s, %s, %s, %s, %s)", model, x, y, w, h)
-        if not self.visible(model):
-            self._models[model].shown = True
+        s = self._models[model]
+        if s.shown:
+            s.shown = True
             model.set_property("iconic", False)
             model.ownership_election()
-        self._models[model].geom = [x, y, w, h]
+        s.geom = [x, y, w, h]
         model.maybe_recalculate_geometry_for(self)
+        asize = model.get_property("actual-size")
+        if asize:
+            aw, ah = asize
+            if aw!=w or ah!=h:
+                log.warn("DesktopManager: updating model with new size: %sx%s", aw, ah)
+                s.geom = [x, y, aw, ah]
+        return s.geom

     def hide_window(self, model):
         if not model.get_property("iconic"):
@@ -275,7 +283,10 @@

     def _window_resized_signaled(self, wm, window):
-        nw,nh = window.get_property("actual-size")
+        asize = window.get_property("actual-size")
+        if asize is None:
+            return
+        nw,nh = asize
         geom = self._desktop_manager.window_geometry(window)
         log("XpraServer._window_resized_signaled(%s,%s) actual-size=%sx%s, current geometry=%s", wm, window, nw, nh, geom)
         geom[2:4] = nw,nh
@@ -509,7 +520,10 @@
         assert not window.is_OR()
         owx, owy, oww, owh = self._desktop_manager.window_geometry(window)
         log("_process_configure_window(%s) old window geometry: %s", packet[1:], (owx, owy, oww, owh))
-        self._desktop_manager.configure_window(window, x, y, w, h)
+        aw, ah = self._desktop_manager.configure_window(window, x, y, w, h)[:2]
+        if abs(aw-w)>1 or abs(ah-h)>1:
+            log.warn("actual window geometry HACK")
+            self._window_resized_signaled(None, window)
         if self._desktop_manager.visible(window) and (oww!=w or owh!=h):
             self._damage(window, 0, 0, w, h)
         if len(packet)>=7:
@@ -541,7 +555,7 @@
         visible = self._desktop_manager.visible(window)
         log("resize_window to %sx%s, desktop manager set it to %sx%s, visible=%s", w, h, ww, wh, visible)
         if visible:
-            self._damage(window, 0, 0, w, h)
+            self._damage(window, 0, 0, ww, wh)

     def _process_mouse_common(self, proto, wid, pointer, modifiers):
         ss = self._server_sources.get(proto)

If it does, it won't be mergeable as-is... but then we at least know where the problem is. Hopefully it won't create a resize loop where the server then updates its size, causing a new event to be sent to the client.. ad infinitum.