steveren
Newbie
Posts: 24
|
 |
« Reply #15 on: May 01, 2014, 10:30:12 PM » |
|
Mike, these logs are from Sysinternals' (now part of Microsoft) procmon tool. THEY SHOW ACTUAL OPERATING SYSTEM CALLS. There are no 'heuristics' and it doesn't matter what you think your code is doing, I'm telling you what Windows says your code is doing. Maybe you are using some third-party library, but something somewhere is doing it. First, you are making many assumptions about what needs to be done and what you think should be done If you can explain to me why moving an image on the page needs the entire queue to be re-read, then I will apologise for making assumptions. I'll try out 215 and see what happens, but don't blame the messenger. |
|
|
|
|
Logged
|
|
|
|
steveren
Newbie
Posts: 24
|
|
« Reply #16 on: May 01, 2014, 10:54:13 PM » |
|
Ah, 215 is definitely a big step in the right direction :-) It's still re-scanning the queue unnecessarily, but at least it's doing so in a much more sensible manner. Let me show you what kind of things were happening with 214: Time of Day Operation Path Detail
18:45:20.5794889 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
18:45:20.5795171 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
18:45:20.5795304 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 2, Length: 1, Priority: Normal
18:45:20.5795402 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 3, Length: 1, Priority: Normal
18:45:20.5795496 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 4, Length: 2, Priority: Normal
18:45:20.5795632 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 6, Length: 10,385, Priority: Normal
18:45:20.5795995 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 10,391, Length: 1, Priority: Normal
18:45:20.5796103 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 10,392, Length: 1, Priority: Normal
18:45:20.5796198 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 10,393, Length: 2, Priority: Normal
18:45:20.5796299 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 20,697, Length: 1, Priority: Normal
18:45:20.5796411 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 20,698, Length: 1, Priority: Normal
18:45:20.5796505 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 20,699, Length: 2, Priority: Normal
18:45:20.5796606 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,275, Length: 1, Priority: Normal
18:45:20.5796700 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,276, Length: 1, Priority: Normal
18:45:20.5796802 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,277, Length: 2, Priority: Normal
18:45:20.5796913 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,279, Length: 693, Priority: Normal
18:45:20.5797043 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,972, Length: 1, Priority: Normal
18:45:20.5797140 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,973, Length: 1, Priority: Normal
18:45:20.5797231 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,974, Length: 2, Priority: Normal
18:45:20.5797332 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,988, Length: 1, Priority: Normal
18:45:20.5797465 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,989, Length: 1, Priority: Normal
18:45:20.5797563 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21,990, Length: 2, Priority: Normal
18:45:20.5797664 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,122, Length: 1, Priority: Normal
18:45:20.5797783 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,123, Length: 1, Priority: Normal
18:45:20.5797877 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,124, Length: 2, Priority: Normal
18:45:20.5797978 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,141, Length: 1, Priority: Normal
18:45:20.5798072 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,142, Length: 1, Priority: Normal
18:45:20.5798167 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,143, Length: 2, Priority: Normal
18:45:20.5798268 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,147, Length: 1, Priority: Normal
18:45:20.5798362 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,148, Length: 1, Priority: Normal
18:45:20.5798456 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,149, Length: 2, Priority: Normal
18:45:20.5798558 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,567, Length: 1, Priority: Normal
18:45:20.5798652 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,568, Length: 1, Priority: Normal
18:45:20.5798743 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,569, Length: 2, Priority: Normal
18:45:20.5798844 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22,581, Length: 1, Priority: Normal
18:45:20.5801933 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
18:45:20.5802164 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 12, Length: 1, Priority: Normal
18:45:20.5802310 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 13, Length: 1, Priority: Normal
18:45:20.5802464 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 16, Length: 1, Priority: Normal
18:45:20.5802642 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 17, Length: 1, Priority: Normal
18:45:20.5802792 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 18, Length: 1, Priority: Normal
18:45:20.5802939 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 19, Length: 1, Priority: Normal
18:45:20.5803085 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 20, Length: 1, Priority: Normal
18:45:20.5803225 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 21, Length: 1, Priority: Normal
18:45:20.5803368 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 22, Length: 1, Priority: Normal
18:45:20.5803508 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 23, Length: 1, Priority: Normal
18:45:20.5803651 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 24, Length: 1, Priority: Normal
18:45:20.5803801 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 25, Length: 1, Priority: Normal
18:45:20.5803944 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 26, Length: 1, Priority: Normal
18:45:20.5804087 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 27, Length: 1, Priority: Normal
18:45:20.5804234 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 28, Length: 1, Priority: Normal
18:45:20.5804391 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 29, Length: 1, Priority: Normal
18:45:20.5804534 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 30, Length: 1, Priority: Normal
18:45:20.5804670 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 31, Length: 1, Priority: Normal
18:45:20.5804810 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 32, Length: 1, Priority: Normal
18:45:20.5804949 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 33, Length: 1, Priority: Normal
18:45:20.5805089 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 30, Length: 1, Priority: Normal
18:45:20.5805229 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 31, Length: 1, Priority: Normal
18:45:20.5805375 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 62, Length: 1, Priority: Normal
18:45:20.5805511 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 63, Length: 1, Priority: Normal
18:45:20.5805651 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 64, Length: 1, Priority: Normal
18:45:20.5805791 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 65, Length: 1, Priority: Normal
18:45:20.5805934 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 66, Length: 1, Priority: Normal
18:45:20.5806073 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 67, Length: 1, Priority: Normal
18:45:20.5806213 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 68, Length: 1, Priority: Normal
18:45:20.5806353 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 69, Length: 1, Priority: Normal
18:45:20.5806503 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 34, Length: 1, Priority: Normal
18:45:20.5806642 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 35, Length: 1, Priority: Normal
18:45:20.5806785 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 36, Length: 1, Priority: Normal
18:45:20.5806925 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 37, Length: 1, Priority: Normal
18:45:20.5807065 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 38, Length: 1, Priority: Normal
18:45:20.5807204 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 39, Length: 1, Priority: Normal
18:45:20.5807354 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 40, Length: 1, Priority: Normal
18:45:20.5807494 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 41, Length: 1, Priority: Normal
18:45:20.5807637 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 42, Length: 1, Priority: Normal
18:45:20.5807777 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 43, Length: 1, Priority: Normal
18:45:20.5807916 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 44, Length: 1, Priority: Normal
18:45:20.5808053 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 45, Length: 1, Priority: Normal
18:45:20.5808196 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 42, Length: 1, Priority: Normal
18:45:20.5808335 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 43, Length: 1, Priority: Normal
and that's just a tiny fragment! Now, with 215 we have, Time of Day Operation Path Detail
23:38:07.9378463 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9378735 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9385815 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:07.9436177 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9450461 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9450636 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9455425 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:07.9458382 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:07.9512225 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:07.9546062 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1516328 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1516751 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1527174 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.1576423 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1587981 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1588152 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1597358 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:09.1601899 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.1661156 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.1702149 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.4348676 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:09.4351559 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.4413609 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.4439406 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.2167168 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:10.2170013 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.2221143 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.2245474 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.3924214 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104414-0002.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.3941661 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104414-0002.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.3974841 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104320-0001.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.3995682 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104320-0001.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4028778 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113048-0003.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4048243 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113048-0003.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4087316 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113458-0004.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4116936 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113458-0004.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4151216 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4188303 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4222834 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144427-0006.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4258465 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144427-0006.jpg Offset: 0, Length: 2, Priority: Normal
Still some redundancy in the reading but far less! It's still noticeably less snappy than 137 but definitely back in the realm of usability :-) |
|
|
|
|
Logged
|
|
|
|
|
admin
|
|
« Reply #17 on: May 02, 2014, 12:12:34 AM » |
|
Ah, 215 is definitely a big step in the right direction :-)
It's still re-scanning the queue unnecessarily, but at least it's doing so in a much more sensible manner.
Easy. I'll give you two simple examples. If you're in one of the automatic placement modes, changing the size of the last image (or images) in the queue can move it to a prior page: didn't fit before on the prior page, now it does. It gets worse if you are working on an image in the middle of the job. Another example, you've had QU open for a while and you're using other programs (like a photo editor). You edit one of the images on page 1, maybe even changing the size of that image, and then you save it. In QU's pagination routine, it has to check all images on all pages to determine if they are the same resolution, orientation, that the specifics of that image (in the EXIF) like color space haven't changed, and that the time/date hasn't changed. If this isn't done after each operation that results in any change to your job, you'll be unaware that the job you see on screen isn't the one that is actually going to print. Some changes could even push images you are currently looking at/working with on one page to push off to other pages or images from prior pages to end up on the page you are working with. And... it only does the minimum it needs to in order to determine that: it isn't reading the images; just headers, modified date/time, and such. It's possible that the pagination process could be "short cut" if the entire document is in freehand mode and you're working on the last page but I don't see putting that code in (and the potential bugs it could cause) being worth it to gain .25 seconds of refresh time on a job with 200 prints. Now, with 215 we have, Time of Day Operation Path Detail
23:38:07.9378463 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9378735 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9385815 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:07.9436177 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9450461 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9450636 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:07.9455425 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:07.9458382 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:07.9512225 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:07.9546062 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1516328 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1516751 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1527174 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.1576423 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1587981 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1588152 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.1597358 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:09.1601899 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.1661156 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.1702149 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:09.4348676 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:09.4351559 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.4413609 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:09.4439406 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.2167168 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 50, Priority: Normal
23:38:10.2170013 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.2221143 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.2245474 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.3924214 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104414-0002.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.3941661 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104414-0002.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.3974841 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104320-0001.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.3995682 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-104320-0001.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4028778 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113048-0003.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4048243 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113048-0003.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4087316 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113458-0004.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4116936 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-113458-0004.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4151216 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4188303 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144212-0005.jpg Offset: 0, Length: 2, Priority: Normal
23:38:10.4222834 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144427-0006.jpg Offset: 0, Length: 1,024, Priority: Normal
23:38:10.4258465 ReadFile C:\Users\steve\Pictures\Malta 2014\20140221-144427-0006.jpg Offset: 0, Length: 2, Priority: Normal
Still some redundancy in the reading but far less! It's still noticeably less snappy than 137 but definitely back in the realm of usability :-) As far as reading a few bytes at a time, that's pretty typical of software that reads EXIF information. You seek to a location in the file, read a few bytes that tells you the next IFD in the header, that gives you a new offset, you seek to that offset, pick up the next entry, and continue. Each entry in the IFD tell you where you need to seek in the file and how many bytes need to be read for that entry. Without parsing the header in this fashion, the only option is to read the ENTIRE file into a buffer, so this is very efficient. And as I'm sure you know, the OS doesn't actually read one byte at a time from the file. It is buffered by sector. So while QU is parsing in that fashion, there is absolutely nothing wrong with it! The only thing I see in your log (I use the same ProcMon BTW) is that while I can expect two or possibly three reads from the first few bytes of the file as there may be several procedures (and even multiple threads) accessing the same file or reading the header/formatting bytes, there is no way I can recreate as many reads from offset 0 as you are showing. I can get two and sometimes three reads of the first 2 or 4 bytes in the file which is to be expected (and again, no problem at all since after the first read, you're just accessing RAM anyway). For me to find an explanation for the extras you're seeing, I'd need to know exactly what operation you performed in order to see those. Moving the mouse over a JPEG, adding the JPEG to the queue, etc. only causes 2-3 reads of the same bytes for me for a given file: only once at the beginning of the file and never repeating after that. But again, I think it's really become counterproductive at this point. I'm not finding 215 any slower than 137 and in some cases quite a bit faster. Mike |
|
|
|
« Last Edit: May 02, 2014, 12:20:27 AM by admin »
|
Logged
|
|
|
|
steveren
Newbie
Posts: 24
|
|
« Reply #18 on: May 02, 2014, 12:52:42 AM » |
|
Sorry... looks like I hit the edit button again instead of quote...
|
|
|
|
« Last Edit: May 02, 2014, 04:08:37 PM by admin »
|
Logged
|
|
|
|
|
admin
|
|
« Reply #19 on: May 02, 2014, 04:12:56 PM » |
|
Sorry: wasn't able to retrieve your post that I edited by mistake because I closed FireFox before I could recover it so I just removed it with a note because I didn't want it to look like you posted something that had my replies. In any case, I was able to find one more area to improve where more information than necessary was being read from some image formats (hence why I wasn't seeing it all the time). I had been working mostly with raw and TIFF but I noticed the potential for improvement when I went crazy and added every image in my "testimages" folder (about 1100 images) and started tracing. Found some JPEG's and a couple others that were being read more than once which could obviously be more efficient.
The final speed improvement will be a part of 216 and it will be faster than any prior version when doing any type of operation on the job!
Mike
|
|
|
|
« Last Edit: May 02, 2014, 04:15:11 PM by admin »
|
Logged
|
|
|
|
|
Terry-M
|
|
« Reply #20 on: May 03, 2014, 08:42:34 AM » |
|
I have been following this thread with curiosity but I don't often have more than 100 images in the queue so I have done some tests of my own. Rather than use terms like "treacle" or references to coffee types, I did some simple measurements of queue operation times. This is what matters for a user, not what happens "under the bonnet".  I used two different folders, one with 299 jpegs and the other with 1256 jpegs. Also, multiple images per page were compared to single images per page because I knew that QU had extra background work to do when using a placement method like Optimal Spaced with multiple images on a page. I also checked the times for adding a single image to the queue. The PC is W7-67, Intel i7 3.6GHz, 6GB ram. I would agree that v214 was noticeably slower when 100 plus images were added to the queue, but it was still usable! See table attached below where QU 2014.137 is compared to 2014.216 It can be seen that v216 is noticeably faster in many of the operations. So, thanks to Mike for getting to the bottom of the issue and making this improvement to QU, regardless of the fact that many users will not see a difference because their queue sizes are small. You would not get this individual service from many software developers I could name. Terry |
|
|
|
« Last Edit: May 03, 2014, 08:48:37 AM by Terry-M »
|
Logged
|
|
|
|
steveren
Newbie
Posts: 24
|
|
« Reply #21 on: May 03, 2014, 11:11:30 AM » |
|
I would agree that v214 was noticeably slower when 100 plus images were added to the queue, but it was still usable!
Just to clarify, it was 213 that was the worst by far, and I was certainly not helping it by having my images on a networked drive. While Mike seems reluctant to say directly "there was a significant bug and I've fixed it", that is rather the impression I have :-) But just as a matter of interest, you might like to try this experiment with different versions. Select freehand placement and add an image to a new page at the end of the queue. Edit that page and type a new value into one of the location boxes to move the image on the page. Nothing else, just move it a bit. 137 is instant, 213 is, err..., not! 214 and 215 were better but still not 137-speed. 216 I've yet to try because I had to do some actual work instead of playing with my photos. |
|
|
|
|
Logged
|
|
|
|
|
Terry-M
|
|
« Reply #22 on: May 03, 2014, 11:39:35 AM » |
|
Hi, Thanks for you comments, I'll try your other "test" when I get a moment. While Mike seems reluctant to say directly "there was a significant bug and I've fixed it", that is rather the impression I have :-) I would not have regarded that as a "bug" as such because it still did work and QU did not crash - an "inefficiency" would be more appropriate  Mike is never reluctant to improve the product where it benefits users and he will probe such queries and ask questions. Like he said, you did not really give any details of the process and end result regarding prints you were trying to achieve, step by step and in the end he had to deduce that from a poor quality video. Don't feel too bad, it's a common problem that users do not give details of what they want to do and it takes a while to draw that out. Enjoy your QU prints! Terry |
|
|
|
|
Logged
|
|
|
|
|
Terry-M
|
|
« Reply #23 on: May 03, 2014, 11:59:13 AM » |
|
I might also add:
What other software would be so attentive, responsive and tuned to his users?
Terry
|
|
|
|
|
Logged
|
|
|
|
steveren
Newbie
Posts: 24
|
|
« Reply #24 on: May 03, 2014, 12:09:38 PM » |
|
I would not have regarded that as a "bug" as such because it still did work and QU did not crash - an "inefficiency" would be more appropriate If it was my own code, I'd call it a bug, but I accept that opinions can differ :-) a poor quality video.
Ah, I didn't realise how bad that was; I just checked the first few seconds before uploading and they were fine. Later it does indeed become hard to tell what's going on but unfortunately nobody told me that :-( Don't feel too bad, it's a common problem that users do not give details
Tell me about it! That's why I posted the video, thinking it would answer any questions about exactly what I was doing. Unfortunately the tool I would previously have used for screen capture doesn't work on Win7 and I was using a different one I'm not familiar with. But anyway, I've now tried 216 and it's fine unless you have your images on a networked drive. Although it's no longer doing masses of unnecessary reading, it's still scanning the queue resulting in many network round trips. With 189 images in the queue, it takes about 8 seconds on my test machine to move an image on the page. 137 is near-as-dammit instant. As it happens, the job I'm doing now can be done on the machine that holds the image files, but it's still a pity that there has been such a significant regression from 137. Perhaps it offers benefits that outweigh the cost for most people if not for me. |
|
|
|
|
Logged
|
|
|
|
|
admin
|
|
« Reply #25 on: May 03, 2014, 12:50:38 PM » |
|
If it was my own code, I'd call it a bug, but I accept that opinions can differ :-) Feel free to call it a bug if it's your code.  Me, I'll call it what it is in my own code: code optimization. But anyway, I've now tried 216 and it's fine unless you have your images on a networked drive. Although it's no longer doing masses of unnecessary reading, it's still scanning the queue resulting in many network round trips. With 189 images in the queue, it takes about 8 seconds on my test machine to move an image on the page. 137 is near-as-dammit instant. 216 is faster than 137 in every way: reference Terry's timing chart above as I think he did a thorough job showing that there is not a single test where 137 is better! 216 is even faster on a network drive by my tests. 216 never reloads files as it caches the information locally. So let me ask this: you're not doing something silly like picking your network drive as the application data folder are you (during install)? That's the only way I can see you having a problem with performance: if you click Utilities, Explore Qimage Application Data in QU and that is pointing to a network drive. All that said, when I have images on a network drive, I always copy them to the local drive to work with them. IF I make any changes and need to update them after I'm done, I just copy only the changes back across the network to their original location. QU's Flash Card Copy/Move function is perfect for that: you can update only what has changed on source/destination very efficiently. I do this because I know how horribly inefficient network file I/O is. Due to the way the OS handles data requests and the network packet overhead, even with a gigabit network file I/O is very inefficient so if you know you'll be working with multiple files, the local copy is a good idea anyway. Mike |
|
|
|
|
Logged
|
|
|
|
steveren
Newbie
Posts: 24
|
|
« Reply #26 on: May 03, 2014, 03:29:09 PM » |
|
216 is faster than 137 in every way: reference Terry's timing chart above as I think he did a thorough job showing that there is not a single test where 137 is better!
Well I've got a test that shows exactly that! Actually, it's not a 'test' as such, it's the real job I'm trying to do. 216 never reloads files as it caches the information locally.
It's not reloading files, but it's still doing network I/O. Here's the scenario: Last page of my job, with 189 images in the queue, in the edit page function. I click on the procmon start-capture button, click back on Qimage window and enter '0' into the left location box. When Qimage finally finishes the move I stop the capture. Result is that 137 issues 1,085 I/O calls for network files, 216 issues 4,633. Now none of these are reads in either case, but 216 still does over four times as many. What happens with 137 is that for all the image files not on the current page, it calls CreateFile(), QueryBasicInformationFile() and CloseFile() which is not too unreasonable, then for each file on the current page it checks for an associated .flt 24 times, then checks the image file 13 times! That's pretty inefficient, but it's only for the last page so it's not so bad overall. Now we compare 216: for images on previous pages it does 6 checks for a .flt and three metadata checks. For images on the last page, it does 19 .flt checks and 9 metadata cycles. This doesn't sound like it should be faster and indeed it isn't! So let me ask this: you're not doing something silly like picking your network drive as the application data folder are you (during install)?
Nope, nothing like that. It's just the image files that are remote. All that said, when I have images on a network drive, I always copy them to the local drive to work with them.
For the work I'm doing, there's no need for network overhead to impose a noticeable penalty, and while 137 turns out to be less efficient than it could be, it doesn't really. 216 does. Sorry, but no matter how many times you tell me 216 is faster than 213, it's simply not so in the scenario above, and by a very significant margin: as I said, about 8 seconds for a simple move compared to barely 1s if that. |
|
|
|
|
Logged
|
|
|
|
|
ed_k
|
|
« Reply #27 on: May 03, 2014, 03:46:56 PM » |
|
So I'm curious. If, in your opinion, QU post-137 is so bad, why do you continue to use it? Or, put another way, if 137 is so good why not continue to use that when the situation calls for it? Or another option is to use a competitor's product - a competitor who certainly would have held this one-on-one personal dialogue with you and fixed whatever is bothering you days ago. |
|
|
|
|
Logged
|
|
|
|
steveren
Newbie
Posts: 24
|
|
« Reply #28 on: May 03, 2014, 05:08:53 PM » |
|
I'm sorry if anyone thinks I'm being unfair or unreasonable. I've been using Qimage for many years and it's still the best at what it does. For the moment, I am sticking with 137, but sooner or later there's likely to be some new feature I do want badly and I'd rather not have to take one step back while taking a different step forward.
So when Mike says "x is faster than 137" and it's plainly not, then what am I to do? Pretend that I see what I'm being told when I don't? Just quietly go away on the grounds that Adobe probably wouldn't have even bothered to respond at all?
There's a real issue here and I'm trying to be constructive in helping solve it, hence things like analysing the procmon logs to see where the bottlenecks are actually arising.
|
|
|
|
|
Logged
|
|
|
|
|
admin
|
|
« Reply #29 on: May 03, 2014, 06:23:23 PM » |
|
So when Mike says "x is faster than 137" and it's plainly not, then what am I to do? Pretend that I see what I'm being told when I don't? Just quietly go away on the grounds that Adobe probably wouldn't have even bothered to respond at all?
Let's look at it another way. Terry posted a very comprehensive 137 vs 216 performance test with actual times for both. Every time on the list was equal to or faster than 137, almost all showed 216 significantly faster. This mirrors what I see here, so until you can post actual numbers or I can find some way to reproduce your results, the only thing I know at this point is that I have confirmation from a third party to substantiate that 216 is significantly faster than 137. So far you have none... or I have not found the right combination to unlock what is happening on your particular machine... or some combination of both. Mike |
|
|
|
|
Logged
|
|
|
|
|
Qimage registration expired? New lifetime licenses are only $59.99!
