AnHardt / Marlin

Reprap FW with look ahead. SDcard and LCD support. It works on Gen6, Ultimaker, RAMPS and Sanguinololu
GNU General Public License v3.0
1 stars 1 forks source link

Searching for Lcd speed (experimental) #66

Closed AnHardt closed 7 years ago

AnHardt commented 7 years ago

This PR documents the search for some more speed and a better distribution of the needed time for display updates.

An other PR will be made to provide the results of this search.

Let's begin with a little benchmark addition to find out what we are talking about.

Provides some output about the time spent for display updates on the serial.

AnHardt commented 7 years ago
...
15:05:09.325 : echo:LCD_update: 17
15:05:09.362 : echo:LCD_update: 21
15:05:09.374 : echo:LCD_update_summ: 38
15:05:09.406 : echo:LCD_update_summ: 0
15:05:09.509 : echo:LCD_update_summ: 0
15:05:09.608 : echo:LCD_update_summ: 0
15:05:09.710 : echo:LCD_update_summ: 0
15:05:09.809 : echo:LCD_update_summ: 0
15:05:09.906 : echo:LCD_update_summ: 0
15:05:10.008 : echo:LCD_update_summ: 0
15:05:10.108 : echo:LCD_update_summ: 0
15:05:10.210 : echo:LCD_update_summ: 0
15:05:10.324 : echo:LCD_update: 18
15:05:10.361 : echo:LCD_update: 23
15:05:10.377 : echo:LCD_update_summ: 41
15:05:10.406 : echo:LCD_update_summ: 0
15:05:10.509 : echo:LCD_update_summ: 0
15:05:10.606 : echo:LCD_update_summ: 0
15:05:10.709 : echo:LCD_update_summ: 0
15:05:10.808 : echo:LCD_update_summ: 0
15:05:10.910 : echo:LCD_update_summ: 0
15:05:11.008 : echo:LCD_update_summ: 0
15:05:11.106 : echo:LCD_update_summ: 0
15:05:11.209 : echo:LCD_update_summ: 0
15:05:11.324 : echo:LCD_update: 17
15:05:11.360 : echo:LCD_update: 21
15:05:11.377 : echo:LCD_update_summ: 38
...

The first test with a REPRAP_DISCOUNT_FULL_GRAPHIC_SMART_CONTROLLER shows a average time for the complete display update of ~40ms. A fluctuation of ~38 to ~41ms. Likely this is caused by interrupts. This measurement was made directly after the upload and connecting RH (Repetier Host). Later on we will see it makes a difference, for example if we homed the machine or not. If i do not talk about measuring directly after the boot i'll mention that. The second thing we can see is, displaying the two 'stripes' takes different times. In both stripes we try to draw the same content - so u8glib (v1.19.1) makes the difference. Likely there is an internal clipping.

// Travis errors result from multiple defined graphics controllers

AnHardt commented 7 years ago

Testing a REPRAP_DISCOUNT_SMART_CONTROLLER. Same conditions as above.

15:34:42.857 : echo:LCD_update: 20
15:34:42.858 : echo:LCD_update_summ: 20
15:34:42.939 : echo:LCD_update_summ: 0
15:34:43.040 : echo:LCD_update_summ: 0
15:34:43.140 : echo:LCD_update_summ: 0
15:34:43.241 : echo:LCD_update_summ: 0
15:34:43.341 : echo:LCD_update_summ: 0
15:34:43.441 : echo:LCD_update_summ: 0
15:34:43.542 : echo:LCD_update_summ: 0
15:34:43.643 : echo:LCD_update_summ: 0
15:34:43.743 : echo:LCD_update_summ: 0
15:34:43.861 : echo:LCD_update: 19
15:34:43.863 : echo:LCD_update_summ: 19
15:34:43.945 : echo:LCD_update_summ: 0
15:34:44.045 : echo:LCD_update_summ: 0
15:34:44.145 : echo:LCD_update_summ: 0
15:34:44.246 : echo:LCD_update_summ: 0
15:34:44.346 : echo:LCD_update_summ: 0
15:34:44.447 : echo:LCD_update_summ: 0
15:34:44.548 : echo:LCD_update_summ: 0
15:34:44.647 : echo:LCD_update_summ: 0
15:34:44.748 : echo:LCD_update_summ: 0
15:34:44.868 : echo:LCD_update: 20
15:34:44.870 : echo:LCD_update_summ: 20

Average time needed is ~20ms - so about twice as fast as a REPRAP_DISCOUNT_FULL_GRAPHIC_SMART_CONTROLLER

AnHardt commented 7 years ago

With a VIKI2 we see

...
15:42:37.947 : echo:LCD_update: 8
15:42:37.953 : echo:LCD_update: 6
15:42:37.960 : echo:LCD_update: 7
15:42:37.979 : echo:LCD_update: 18
15:42:37.993 : echo:LCD_update: 13
15:42:38.011 : echo:LCD_update: 17
15:42:38.028 : echo:LCD_update: 16
15:42:38.046 : echo:LCD_update: 16
15:42:38.047 : echo:LCD_update_summ: 101
15:42:38.048 : echo:LCD_update_summ: 0
15:42:38.148 : echo:LCD_update_summ: 0
15:42:38.250 : echo:LCD_update_summ: 0
15:42:38.349 : echo:LCD_update_summ: 0
15:42:38.450 : echo:LCD_update_summ: 0
15:42:38.551 : echo:LCD_update_summ: 0
15:42:38.651 : echo:LCD_update_summ: 0
15:42:38.752 : echo:LCD_update_summ: 0
15:42:38.853 : echo:LCD_update_summ: 0
15:42:38.961 : echo:LCD_update: 8
15:42:38.967 : echo:LCD_update: 6
15:42:38.974 : echo:LCD_update: 6
15:42:38.994 : echo:LCD_update: 19
15:42:39.009 : echo:LCD_update: 13
15:42:39.026 : echo:LCD_update: 16
15:42:39.043 : echo:LCD_update: 17
15:42:39.060 : echo:LCD_update: 16
15:42:39.061 : echo:LCD_update_summ: 101
15:42:39.062 : echo:LCD_update_summ: 0
15:42:39.162 : echo:LCD_update_summ: 0
15:42:39.263 : echo:LCD_update_summ: 0
15:42:39.364 : echo:LCD_update_summ: 0
15:42:39.464 : echo:LCD_update_summ: 0
15:42:39.566 : echo:LCD_update_summ: 0
15:42:39.667 : echo:LCD_update_summ: 0
15:42:39.766 : echo:LCD_update_summ: 0
15:42:39.867 : echo:LCD_update_summ: 0
15:42:39.977 : echo:LCD_update: 9
15:42:39.983 : echo:LCD_update: 6
15:42:39.990 : echo:LCD_update: 6
15:42:40.009 : echo:LCD_update: 18
15:42:40.024 : echo:LCD_update: 14
15:42:40.040 : echo:LCD_update: 16
15:42:40.058 : echo:LCD_update: 16
15:42:40.075 : echo:LCD_update: 17
15:42:40.077 : echo:LCD_update_summ: 102
...

The display update divided in 8 stripes, together taking about 101ms. That's about 2.5 tines slower than the REPRAP_DISCOUNT_FULL_GRAPHIC_SMART_CONTROLLER. Even here we find time/stripe differing a lot.

The VIKI2 test is not made on real hardware. Because there is no feedback of the display this should not make a difference.

AnHardt commented 7 years ago

VIKI2 without LCD_SCREEN_ROT_180 is vastly improved:

...
15:59:23.349 : echo:LCD_update: 8
15:59:23.358 : echo:LCD_update: 9
15:59:23.367 : echo:LCD_update: 7
15:59:23.377 : echo:LCD_update: 10
15:59:23.391 : echo:LCD_update: 13
15:59:23.397 : echo:LCD_update: 5
15:59:23.402 : echo:LCD_update: 5
15:59:23.409 : echo:LCD_update: 6
15:59:23.411 : echo:LCD_update_summ: 63
15:59:23.443 : echo:LCD_update_summ: 0
15:59:23.543 : echo:LCD_update_summ: 0
15:59:23.644 : echo:LCD_update_summ: 0
15:59:23.744 : echo:LCD_update_summ: 0
15:59:23.845 : echo:LCD_update_summ: 0
15:59:23.945 : echo:LCD_update_summ: 0
15:59:24.046 : echo:LCD_update_summ: 0
15:59:24.146 : echo:LCD_update_summ: 0
15:59:24.247 : echo:LCD_update_summ: 0
15:59:24.356 : echo:LCD_update: 8
15:59:24.364 : echo:LCD_update: 10
15:59:24.373 : echo:LCD_update: 7
15:59:24.383 : echo:LCD_update: 8
15:59:24.397 : echo:LCD_update: 13
15:59:24.403 : echo:LCD_update: 6
15:59:24.408 : echo:LCD_update: 5
15:59:24.415 : echo:LCD_update: 7
15:59:24.417 : echo:LCD_update_summ: 64
15:59:24.448 : echo:LCD_update_summ: 0
15:59:24.549 : echo:LCD_update_summ: 0
15:59:24.650 : echo:LCD_update_summ: 0
15:59:24.750 : echo:LCD_update_summ: 0
15:59:24.851 : echo:LCD_update_summ: 0
15:59:24.951 : echo:LCD_update_summ: 0
15:59:25.051 : echo:LCD_update_summ: 0
15:59:25.152 : echo:LCD_update_summ: 0
15:59:25.253 : echo:LCD_update_summ: 0
15:59:25.313 : ok T:0.0 /0.0 @:0
15:59:25.360 : echo:LCD_update: 8
15:59:25.370 : echo:LCD_update: 9
15:59:25.379 : echo:LCD_update: 7
15:59:25.388 : echo:LCD_update: 10
15:59:25.402 : echo:LCD_update: 13
15:59:25.408 : echo:LCD_update: 5
15:59:25.414 : echo:LCD_update: 5
15:59:25.420 : echo:LCD_update: 6
15:59:25.422 : echo:LCD_update_summ: 63
...

So if you have a chance turn you VIKI2 or miniVIKI upside down and comment LCD_SCREEN_ROT_180. ;-)

AnHardt commented 7 years ago

Test 5: VIKI2 without LCD_SCREEN_ROT_180 and a stock u8glib device using 4 instead of 8 strives is not sooo bad. Nearly the same speed as REPRAP_DISCOUNT_FULL_GRAPHIC_SMART_CONTROLLER with Marlin special ST7920 driver.

...
16:35:58.582 : echo:LCD_update: 9
16:35:58.596 : echo:LCD_update: 13
16:35:58.611 : echo:LCD_update: 14
16:35:58.620 : echo:LCD_update: 7
16:35:58.622 : echo:LCD_update_summ: 43
16:35:58.673 : echo:LCD_update_summ: 0
16:35:58.774 : echo:LCD_update_summ: 0
16:35:58.875 : echo:LCD_update_summ: 0
16:35:58.975 : echo:LCD_update_summ: 0
16:35:59.076 : echo:LCD_update_summ: 0
16:35:59.177 : echo:LCD_update_summ: 0
16:35:59.277 : echo:LCD_update_summ: 0
16:35:59.378 : echo:LCD_update_summ: 0
16:35:59.479 : echo:LCD_update_summ: 0
16:35:59.587 : echo:LCD_update: 9
16:35:59.601 : echo:LCD_update: 12
16:35:59.616 : echo:LCD_update: 15
16:35:59.625 : echo:LCD_update: 7
16:35:59.627 : echo:LCD_update_summ: 43
16:35:59.679 : echo:LCD_update_summ: 0
16:35:59.780 : echo:LCD_update_summ: 0
16:35:59.880 : echo:LCD_update_summ: 0
16:35:59.981 : echo:LCD_update_summ: 0
16:36:00.082 : echo:LCD_update_summ: 0
16:36:00.182 : echo:LCD_update_summ: 0
16:36:00.283 : echo:LCD_update_summ: 0
16:36:00.384 : echo:LCD_update_summ: 0
16:36:00.470 : ok T:0.0 /0.0 @:0
16:36:00.484 : echo:LCD_update_summ: 0
16:36:00.593 : echo:LCD_update: 9
16:36:00.606 : echo:LCD_update: 13
16:36:00.623 : echo:LCD_update: 14
16:36:00.631 : echo:LCD_update: 7
16:36:00.633 : echo:LCD_update_summ: 43
...
AnHardt commented 7 years ago

Back to my real hardware.

Test 6: REPRAP_DISCOUNT_FULL_GRAPHIC_SMART_CONTROLLER with stock u8glib device

Comparable because also with 2 stripes.

16:51:34.752 : echo:LCD_update: 15
16:51:34.806 : echo:LCD_update: 20
16:51:34.834 : echo:LCD_update_summ: 35
16:51:34.838 : echo:LCD_update_summ: 0
16:51:34.940 : echo:LCD_update_summ: 0
16:51:35.039 : echo:LCD_update_summ: 0
16:51:35.137 : echo:LCD_update_summ: 0
16:51:35.240 : echo:LCD_update_summ: 0
16:51:35.338 : echo:LCD_update_summ: 0
16:51:35.440 : echo:LCD_update_summ: 0
16:51:35.539 : echo:LCD_update_summ: 0
16:51:35.637 : echo:LCD_update_summ: 0
16:51:35.756 : echo:LCD_update: 16
16:51:35.805 : echo:LCD_update: 21
16:51:35.834 : echo:LCD_update_summ: 37
16:51:35.838 : echo:LCD_update_summ: 0
16:51:35.940 : echo:LCD_update_summ: 0
16:51:36.038 : echo:LCD_update_summ: 0
16:51:36.140 : echo:LCD_update_summ: 0
16:51:36.239 : echo:LCD_update_summ: 0
16:51:36.342 : echo:LCD_update_summ: 0
16:51:36.440 : echo:LCD_update_summ: 0
16:51:36.538 : echo:LCD_update_summ: 0
16:51:36.641 : echo:LCD_update_summ: 0
16:51:36.755 : echo:LCD_update: 15
16:51:36.804 : echo:LCD_update: 20
16:51:36.832 : echo:LCD_update_summ: 35

That's unexpected. Seems to be faster than Marlins device! This was different in my previous test 10 Month ago.

AnHardt commented 7 years ago

Test 7: Back to Marlins device but eleminated the one 'nop'

17:03:43.047 : echo:LCD_update: 18
17:03:43.084 : echo:LCD_update: 23
17:03:43.097 : echo:LCD_update_summ: 41
17:03:43.097 : ok T:0.0 /0.0 @:0
17:03:43.129 : echo:LCD_update_summ: 0
17:03:43.231 : echo:LCD_update_summ: 0
17:03:43.330 : echo:LCD_update_summ: 0
17:03:43.428 : echo:LCD_update_summ: 0
17:03:43.531 : echo:LCD_update_summ: 0
17:03:43.629 : echo:LCD_update_summ: 0
17:03:43.731 : echo:LCD_update_summ: 0
17:03:43.830 : echo:LCD_update_summ: 0
17:03:43.932 : echo:LCD_update_summ: 0
17:03:44.047 : echo:LCD_update: 17
17:03:44.083 : echo:LCD_update: 22
17:03:44.096 : echo:LCD_update_summ: 39
17:03:44.128 : echo:LCD_update_summ: 0
17:03:44.231 : echo:LCD_update_summ: 0
17:03:44.329 : echo:LCD_update_summ: 0
17:03:44.432 : echo:LCD_update_summ: 0
17:03:44.529 : echo:LCD_update_summ: 0
17:03:44.628 : echo:LCD_update_summ: 0
17:03:44.731 : echo:LCD_update_summ: 0
17:03:44.829 : echo:LCD_update_summ: 0
17:03:44.931 : echo:LCD_update_summ: 0
17:03:45.046 : echo:LCD_update: 18
17:03:45.083 : echo:LCD_update: 22
17:03:45.095 : echo:LCD_update_summ: 40

Still about 40ms - so not changed considerably. ???

AnHardt commented 7 years ago

However. We hope to split the big display update into more slices. So now the Marlin device with 4 stripes.

17:17:39.158 : echo:LCD_update: 10
17:17:39.178 : echo:LCD_update: 14
17:17:39.203 : echo:LCD_update: 16
17:17:39.215 : echo:LCD_update: 8
17:17:39.223 : echo:LCD_update_summ: 48
17:17:39.248 : echo:LCD_update_summ: 0
17:17:39.350 : echo:LCD_update_summ: 0
17:17:39.448 : echo:LCD_update_summ: 0
17:17:39.551 : echo:LCD_update_summ: 0
17:17:39.649 : echo:LCD_update_summ: 0
17:17:39.747 : echo:LCD_update_summ: 0
17:17:39.850 : echo:LCD_update_summ: 0
17:17:39.878 : ok T:0.0 /0.0 @:0
17:17:39.948 : echo:LCD_update_summ: 0
17:17:40.050 : echo:LCD_update_summ: 0
17:17:40.157 : echo:LCD_update: 10
17:17:40.181 : echo:LCD_update: 14
17:17:40.201 : echo:LCD_update: 15
17:17:40.218 : echo:LCD_update: 8
17:17:40.222 : echo:LCD_update_summ: 47
17:17:40.247 : echo:LCD_update_summ: 0
17:17:40.349 : echo:LCD_update_summ: 0
17:17:40.448 : echo:LCD_update_summ: 0
17:17:40.550 : echo:LCD_update_summ: 0
17:17:40.648 : echo:LCD_update_summ: 0
17:17:40.751 : echo:LCD_update_summ: 0
17:17:40.849 : echo:LCD_update_summ: 0
17:17:40.947 : echo:LCD_update_summ: 0
17:17:41.049 : echo:LCD_update_summ: 0
17:17:41.156 : echo:LCD_update: 10
17:17:41.181 : echo:LCD_update: 14
17:17:41.201 : echo:LCD_update: 16
17:17:41.217 : echo:LCD_update: 8
17:17:41.221 : echo:LCD_update_summ: 48

As expected the summed time for the update goes up a bit, while the time per stripe shrinks.

AnHardt commented 7 years ago

Test 9: Marlin device with 8 stripes

...
17:27:51.496 : echo:LCD_update: 9
17:27:51.508 : echo:LCD_update: 9
17:27:51.521 : echo:LCD_update: 10
17:27:51.533 : echo:LCD_update: 9
17:27:51.553 : echo:LCD_update: 15
17:27:51.561 : echo:LCD_update: 5
17:27:51.569 : echo:LCD_update: 5
17:27:51.577 : echo:LCD_update: 7
17:27:51.582 : echo:LCD_update_summ: 69
17:27:51.586 : ok T:0.0 /0.0 @:0
17:27:51.586 : echo:LCD_update_summ: 0
17:27:51.684 : echo:LCD_update_summ: 0
17:27:51.786 : echo:LCD_update_summ: 0
17:27:51.885 : echo:LCD_update_summ: 0
17:27:51.987 : echo:LCD_update_summ: 0
17:27:52.086 : echo:LCD_update_summ: 0
17:27:52.188 : echo:LCD_update_summ: 0
17:27:52.286 : echo:LCD_update_summ: 0
17:27:52.384 : echo:LCD_update_summ: 0
17:27:52.495 : echo:LCD_update: 9
17:27:52.507 : echo:LCD_update: 9
17:27:52.519 : echo:LCD_update: 9
17:27:52.532 : echo:LCD_update: 9
17:27:52.552 : echo:LCD_update: 15
17:27:52.560 : echo:LCD_update: 5
17:27:52.569 : echo:LCD_update: 4
17:27:52.581 : echo:LCD_update: 7
17:27:52.585 : echo:LCD_update_summ: 67
17:27:52.585 : echo:LCD_update_summ: 0
17:27:52.688 : echo:LCD_update_summ: 0
17:27:52.785 : echo:LCD_update_summ: 0
17:27:52.888 : echo:LCD_update_summ: 0
17:27:52.986 : echo:LCD_update_summ: 0
17:27:53.089 : echo:LCD_update_summ: 0
17:27:53.187 : echo:LCD_update_summ: 0
17:27:53.286 : echo:LCD_update_summ: 0
17:27:53.388 : echo:LCD_update_summ: 0
17:27:53.494 : echo:LCD_update: 8
17:27:53.506 : echo:LCD_update: 9
17:27:53.519 : echo:LCD_update: 10
17:27:53.531 : echo:LCD_update: 10
17:27:53.551 : echo:LCD_update: 15
17:27:53.559 : echo:LCD_update: 6
17:27:53.568 : echo:LCD_update: 4
17:27:53.580 : echo:LCD_update: 7
17:27:53.585 : echo:LCD_update_summ: 69
...

Summed time is now at about 175% of the 2 stripe version. Time/stripe varies a lot. Some are down to 4ms - that's about 1/5 of the initial duration, while others last about 15ms what's about 3/4 of the initial ~20ms.

Looks as if 4 stripes could be a good compromise.

AnHardt commented 7 years ago

Test 10: Convert inverse bar to a box

The two stripes around the middle take much longer than the oter. Is this reasond by the bar?

...
20:04:29.282 : echo:LCD_update: 11
20:04:29.298 : echo:LCD_update: 12
20:04:29.314 : echo:LCD_update: 8
20:04:29.326 : echo:LCD_update: 7
20:04:29.334 : echo:LCD_update_summ: 38
20:04:29.371 : echo:LCD_update_summ: 0
20:04:29.470 : echo:LCD_update_summ: 0
20:04:29.572 : echo:LCD_update_summ: 0
20:04:29.670 : echo:LCD_update_summ: 0
20:04:29.768 : echo:LCD_update_summ: 0
20:04:29.871 : echo:LCD_update_summ: 0
20:04:29.969 : echo:LCD_update_summ: 0
20:04:30.071 : echo:LCD_update_summ: 0
20:04:30.170 : echo:LCD_update_summ: 0
20:04:30.281 : echo:LCD_update: 10
20:04:30.297 : echo:LCD_update: 12
20:04:30.313 : echo:LCD_update: 8
20:04:30.325 : echo:LCD_update: 7
20:04:30.334 : echo:LCD_update_summ: 37
20:04:30.371 : echo:LCD_update_summ: 0
20:04:30.469 : echo:LCD_update_summ: 0
20:04:30.571 : echo:LCD_update_summ: 0
20:04:30.669 : echo:LCD_update_summ: 0
20:04:30.772 : echo:LCD_update_summ: 0
20:04:30.870 : echo:LCD_update_summ: 0
20:04:30.969 : echo:LCD_update_summ: 0
20:04:31.071 : echo:LCD_update_summ: 0
20:04:31.169 : echo:LCD_update_summ: 0
20:04:31.280 : echo:LCD_update: 10
20:04:31.300 : echo:LCD_update: 12
20:04:31.312 : echo:LCD_update: 8
20:04:31.329 : echo:LCD_update: 8
20:04:31.337 : echo:LCD_update_summ: 38
...

Wow. Setting pixels is slow! Or is it the inverse writing?

AnHardt commented 7 years ago

Shit happens. The benchmark did not contain the transfer time from framebuffer to display (SPI). That is done in u8g.nextPage(). That explains why the Marlin ST7920 device was not better then the stock u8glib one.

Return to start.