Profiling

[Dassadar]

Hello,
My GUI is a bit slow: are there tools within Shoes to profile the code and find where to optimize please?
Regards,
David

[ccoupe]

you can try require 'profile' and launch from cshoes.exe - it might work but it will be blind to a lot of the drawing code. You can do C level profiling but then you don't know what ruby is doing . Also C level is very difficult for most people to set up since neither Ruby, Shoes or the dependent dll's are not built with debugging symbols that could easily take you 3 or 4 days to setup for little insight.

[Dassadar]

Hello,
I both tried (under Windows via cmd):

• require 'profile'
• launching the command shoes -rprofile ...
  In both cases, the app is launched and is slow (making think that a profiling does happen?), however no profiling is displayed on the command window.
  Any idea please?
  Regards,
  David

[ccoupe]

Having never run it myself, I can't help much. It appears that it should output at program exit. It's quite possible that you or Shoes uses a different exit (since it's not really ruby). Perhaps there is a call you can make before quitting? There are other gems that might work but I suspect not.

[IanTrudel]

Ruby Benchmark should do in most cases.

[ccoupe]

https://github.com/ruby-prof/ruby-prof looks interesting. Somebody could try it. The only time I had performance issues with ruby or shoes involved sqlite3 speed at inserting rows and easily diagnosed from observation.

[passenger94]

out of curiosity :
super basic draft : can spy uses of ruby's methods of a Shoes app (at launch time)
filtered by number of times the method is used (count) or total real time spend in a method alone (self time) or total time spend on a method and subsequent method calls (total time)
The more red, the more used

Based on ruby's Process and TracePoint libs and this : https://github.com/emilsoman/diy_prof/tree/dot-reporter

[Dassadar]

I think Benchmark is only to get the total time, not giving a breakdown of elapsed time down to method level.

[Dassadar]

And the other solutions are not very straightforward to implement unfortunately :-/

[IanTrudel]

I think Benchmark is only to get the total time, not giving a breakdown of elapsed time down to method level.

It is not profiling per se but using a profiler through Shoes sounds like challenging because of the extra layer shoes is adding. At best you might be able to profile at Ruby method level but not at Shoes level. You wouldn't get entries for windows, slots, stacks, etc. Benchmark would work though.

Alternatively, you can write your business logic in plain Ruby and profile your code using Ruby instead of Shoes. You will be able to profile Ruby methods and optimize. Then you use Benchmark at Shoes level in areas you feel are bottlenecks.

[ccoupe]

Profiling is difficult. gem install is not difficult now days since they often come with win32 binaries libs. Interpreting the results is difficult. That said, @passenger94 just demonstrated his Shoes app in a profiler with what appears to be a Shoes written method of presentation so it clearly can be done.

[passenger94]

just a start, [ you can only trace an app at launching time, balloons dimensions are bounded to the length of the biggest method name,they could be big ...]
added option to trace C methods

https://gist.github.com/passenger94/61230af6e154973ea960d5f5cd29ac8c
in case you could find a use for, as is ...
First i was hoping to create a graph with connected nodes, without realizing that it is totally not a trivial task, well, it looks like that to me ... Too bad, might be a useful Shoes app (apparently works also on regular ruby scripts, could be easily extended to spy on ruby blocks ...)

[ccoupe]

I don't want this to get lost in the issues, so I started https://github.com/Shoes3/shoes3/wiki/DIY-Profiling This is another Shoes app that uses Shoes, I like those! This is even Shoe4 compatible should they ever arise from grave and notice it. This is one of those Proof of Concept that really showcases Shoes and Ruby. Congratulations.

I hinted at some TODO's in the wiki article. Maybe a less graphical - write strings to an edit_box with
`method_name, count, wall-time, cpu-msec, %wall, %cpu. (or to a csv/sqlite3) and sort after collecting the raw data. So many things for someone to do when they have the time and inclination.

Edit:
I'm not opposed to including a modified version of this in future shoes (3.3.2+) or hosting a new repo .

[passenger94]

Cool !

[ccoupe]

It works well enough to be part of Shoes 3.2.2. Needs a lot more work , of course. I'm going to work on the -e command line option and moving the diy_prof code to a Shoes friendly place. Also functional Ruby makes my head hurt. Better left for someone with skills.

[ccoupe]

Fun. The newer profiler works on OSX (subject to OSX command line funk) and crashes on Win7 when
it starts the trace. Very minimal crash report inside Ruby. I suspect a Tracepoint/MinGW/Ruby (2.2.4) bug. I have no proof of that, just a suspicion. Moving Windows to 2.2.7 (or 8) will take some time.

[ccoupe]

Because I got tired of C and objective C I decide to implement the terminal version of the profiler.

So many bugs. Done so wrong. (remember you can create a wider terminal)

[ccoupe]

This is cosmetically as far as I'm going to go on this issue w/o feedback, or pull requests (after I dig into why Windows fails). Here's two screen shots

[ccoupe]

The Windows crash is because Windows Ruby doesn't implement many posix things.

Process.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :microsecond)

Fails in irb. There does appear to be a way to get the answer with some C code.

[passenger94]

ouch ! cross platform plumbing is an art :-D
looks great !

[ccoupe]

I'm thinking of adding new Shoes methods app.wall_time and app.cpu_time. They could be useful for other purposes than our profiler. Thoughts?

[passenger94]

More tools to fiddle with ? sounds reasonable to me :-)
May i ask what is your current view on "other purpose" ?

[ccoupe]

An quick and easy way to measure the wall time of an sql-query or a download or...

[passenger94]

a way to precisely target the function to be measured ?

[ccoupe]

Any thing that is smaller than what Ruby Time supplies. Who knows? Might not be useful to others.

[ccoupe]

new shoes methods are not going to happen. I know Windows Ruby only supports REAL_TIME and MONOTONIC clocks and if there was an easy way for PROCESS_CPUTIME_ID it would have been included in in win32.c

That's a dos window. Oddly enough, you can set some cross platform colors on it that are compatible. Go figure.

[ccoupe]

@Dassadar there's a beta with the profiler here if you want to try it.

[dredknight]

Heya !

I tried toe Profile but somehow it breaks my code. Here it is what happens.

I open shoes -> Profile an App, then select my main.rb.
Both GUI display and c methods enabled.

When I start the profile the APP starts running but I am unable to click on elements that have click event.

Some files are opened for each clicked event but when launched through the profiler this error appears is "No such file or directory available "text/factions/Academy.txt".

The app works when launched normally. Why is that? Does the default app path gets modified while launched through the profiler?

[ccoupe]

Windows? Depending on the beta version, it may have problems profiling anything on Windows. Try profiling a very simple program to see if it works.

[ccoupe]

Further, I believe profiling does Dir.chdir( to location of script) but that may not work as expected - it works for sample/good-cardflip which loads a file. There is also a bug I just discovered with profiling scripts that use the url/visit method of navigation.

[dredknight]

I am using R2619. I believe what you say is true about Chdir not working as it covers the issue.
Yes I am using windows.

Actually the profiler works and my code gets executed but due to issues with the chdirs with works halfway.

[ccoupe]

Windows and paths and pwd have always been a problem. The r2629 version of shoes 3.3.2 only allows profiling from the command line.

e:\shoes3> cshoes.exe -e \path\to\script.rb

part of the reason for forcing command line only, is the confusion about where the script (and dependencies are located. Putting profile in the splash was a regrettable error.

[dredknight]

hm... tried this but the result was the same :/

e:\shoes3> cshoes.exe -e \path\to\script.rb

[ccoupe]

I did discover some code in samples/good-cardflip.rb that explains why it works -e on Windows/Mac/Linux. It looks in several places for the resource:

  # finding script resources is odd when developing a samples/myprogram.rb
  # particularly on osx when invoked with ./cshoes mydir/myprogram.rb
  # DIR is not sufficient.
  # its best to return a full path.
  def find_paris
    cdir = Dir.getwd
    if File.exist? "paris.svg"
      "#{cdir}/paris.svg"
    elsif File.exist? "#{DIR}/paris.svg"
      "#{DIR}/paris.svg"
    else
      ask_open_file "Locate paris.svg"
    end
  end

This actually not a profiler problem, it's an old Shoes thing with Windows (and sometimes OSX), particularly for a package script. I remember it from Shoes 2. Getting the real directory that your running in with Dir.getwd and then using that value to find your resource is a good work around. Perhaps even a best practice for cross platform Shoes (undocumented - sigh).

Here's the 'offending' code in lib/shoes/profiler.rb starting at line 247

      @trace_button = button 'Start Profile', state: (@file == nil ? "disabled": nil) do
        load_st = Process.clock_gettime(Process::CLOCK_MONOTONIC, :microsecond)
        $shoes_profiler.add_c_calls = @cc.checked?
        Dir.chdir(File.dirname(@file)) do
          $shoes_profiler.start{ eval IO.read(File.basename(@file)).force_encoding("UTF-8"), TOPLEVEL_BINDING }
          load_end = Process.clock_gettime(Process::CLOCK_MONOTONIC, :microsecond)
        end
      end
      @end_button = button 'End Profile' do
        nodes, links = $shoes_profiler.stop(load_st, load_end, Process.clock_gettime(Process::CLOCK_MONOTONIC, :microsecond))

When you press the start button, it does chdir - but only long enough to load and start the script for monitoring. Then current dir will revert to where it was before. you then button click -> load resource of in your script and the current dir is set to ??? - probably where shoes.exe is installed because thats how Windows does things. Opening a script from the Splash screen works because it does a chdir to the script location, without the {block} so it's a permanent change of current dir.
I might try that and see what happens.

But, packaging and cross platform is going to bite you again if you do not use the Dir.getwd trick in your script to find the resources.

[ccoupe]

@dredknight - Shoes 3.3.2 r2630 should fix the problem with cshoes.exe -d setting the wrong path on Windows, My comments above about packaged scripts locating their resources by trying both getwd and DIR paths are still valid although I can predict at least one other contributer here won't believe me. ;-)

[dredknight]

I will test tomorrow :)

[dredknight]

Profiler works correctly with Shoes 3.3.2 r2658.
Looking forward to test it extensively in the following weeks.

A noob profiler question. What can I do if certain tasks like "draw" and "image" take the longest time?
Basically shoes is all about drawing and images.... or may be profiler strength comes when you inspect a code with a lot of logic so you can find which part of the logic is the slowest and can be optimized?

[ccoupe]

Closed in Shoes 3.3.2