Upload to coveralls takes ages

Fuco1 commented 8 years ago

In my smartparens builds on travis, having undercover enabled time outs the builds. This started happening some 20 days ago. When I disable undercover it goes through fine. I suspected evm but it seems this here is the culprit. Any ideas?

At least we should probably add some sort of timeouts to not kill the builds unnecessarily (travis kills the job after 10 minutes of no output).

You can see the builds here https://travis-ci.org/Fuco1/smartparens/jobs/173349781

sviridov commented 8 years ago

Sorry for the late response, I was away on previous week.

You can see the builds here https://travis-ci.org/Fuco1/smartparens/jobs/173349781

I can see Elapsed time 1 min 3 sec for this build... Is this problem still exists? Maybe it was something with coveralls API. If it's true we can add some curl option like --connect-timeout or --max-time.

sviridov commented 8 years ago

Oh, based on this build https://travis-ci.org/Fuco1/smartparens/jobs/173346044 I can say that it's not coveralls API. Probably it's something with edebug. I will take a look.

Fuco1 commented 8 years ago

Dang, I linked the wrong build :blush: However the one you found is the problem, it just waits for 10 minutes for no input then drops the build.

Fuco1 commented 8 years ago

I think the problem is with the undercover macro.

(defmacro undercover (&rest configuration)
  "Enable test coverage for files matched by CONFIGURATION.
Example of CONFIGURATION: (\"*.el\" \"subdir/*.el\" (:exclude \"exclude-*.el\")).
If running under Travic CI automatically generate report
on `kill-emacs' and send it to coveralls.io."
  `(undercover--setup
    (list
     ,@(--map (if (atom it) it `(list ,@it))
              configuration))))

Replacing the --map with -map and explicit lambda should work better.

(defmacro undercover (&rest configuration)
  "Enable test coverage for files matched by CONFIGURATION.
Example of CONFIGURATION: (\"*.el\" \"subdir/*.el\" (:exclude \"exclude-*.el\")).
If running under Travic CI automatically generate report
on `kill-emacs' and send it to coveralls.io."
  `(undercover--setup
    (list
     ,@(-map (lambda (it)
               (if (atom it) it `(list ,@it)))
             configuration))))

The issue might be with byte compilation and load order of the anaphoras... if they get loaded in wrong order they are not compiled as macros and the compiler thinks --map is a function and then it is undefined.

sviridov commented 7 years ago

I did some debugging and it looks like undercover.el (or edebug most likely) has some problems with this function:

(defun sp--strict-regexp-opt (strings &optional ignored)
  "Like regexp-opt, but with extra boundary conditions to ensure
that the strings are not matched in-symbol."
  (if strings
      (with-syntax-table
          ;; HACK: this is a terrible hack to make ' be treated as a
          ;; punctuation.  Many text modes set it as word character which
          ;; messes up the regexps
          (let ((table (make-syntax-table (syntax-table))))
            (modify-syntax-entry ?' "." table)
            table)
        (--> strings
             (-group-by (lambda (string)
                          (list (and (string-match-p "\\`\\<" string) t)
                                (and (string-match-p "\\>\\'" string) t)))
                        it)
             (mapconcat (lambda (g) (apply 'sp--regexp-for-group g)) it "\\|")
             (concat "\\(?:" it "\\)")))
    ""))

If you want to reproduce it locally:

Re-enable undercover.

Add this code to the end of test-helper.el:

(when (s-contains? "--win" (getenv "ERT_RUNNER_ARGS"))
(defun ert-runner/run-tests-batch-and-exit (selector)
  (ert-run-tests-interactively selector)))

Run TRAVIS=true cask exec ert-runner --win from a terminal.

Will continue my investigation.

sviridov commented 7 years ago

Something really strange going on here:)

For test purposes I defined simple function:

(defun test123 (x) (--> x (+ it 2)))

And then I passed it to edebug in my regular Emacs window and window that I got with TRAVIS=true cask exec ert-runner --win command. And result was different. In first case everything was okay, but in second case --> macro was not expanded properly. Function definition was changed to (with edebug and undercover code removed):

(defun test123 (x) (+ it 2))

Indeed, undercover will change function definitions. But it just adds new code to the definition without looking into it. It's done here:

(setf (symbol-function 'undercover--stop-point-after)
      (cons 'macro
        (lambda (before-index after-index form)
          "Increase number of times that stop point at AFTER-INDEX was covered."
         `(let ((before-index ,before-index)
                (after-index ,after-index))
            (unwind-protect ,form
              (when (boundp 'edebug-freq-count)
                (aset edebug-freq-count after-index (+ 1 (aref edebug-freq-count after-index)))
                (undercover--align-counts-between-stop-points before-index after-index)))))))

So, it looks like this form argument is incorrect in this environment for some reason (it comes from edebug). Do you have any ideas why it can happen?

P.S. Just FYI:

Correctly expanded version: http://pastebin.com/nRpY4DNs.
Incorrectly expanded version: http://pastebin.com/N2ffrqRy.

sviridov commented 7 years ago

Okay, I found a problem. I can see that definition of --> is different in this environments. The only difference is (declare (debug ->)) statement. Will dig more into it.

sviridov commented 7 years ago

Yeah, it's definitely some edebug error (or maybe incorrect --> debug specification). I just tried to debug test123 without undercover:

ELISP> (symbol-function 'test123)
(lambda
  (x)
  (edebug-enter 'test123
                (list x)
                #'(lambda nil
                    (edebug-after
                     (edebug-before 0)
                     3
                     (+
                      (edebug-after 0 2 it)
                      2)))))

As you can see it wasn't expanded properly.

Fuco1 commented 7 years ago

Your research points to this commit we merged into dash about at the time things went south: https://github.com/magnars/dash.el/pull/188

Fuco1 commented 7 years ago

@Wilfred any idea what's going on here?

Fuco1 commented 7 years ago

Notice that --> as the only one of the family has different argument list: (x form &rest more) instead of (x &optional form &rest more) ! I guess that's the problem?

sviridov commented 7 years ago

Sorry for the delay.

I did a small experiment. I replaced debug definition for -> from

  (declare (debug (&rest form &rest [&or symbolp (sexp &rest form)])))

to

  (declare (debug (&rest sexp &rest [&or symbolp (sexp &rest sexp)])))

and it fixed "Symbol's value as variable is void: it" issue for me. But I'm not 100% sure that it's correct way of doing it.

But unfortunately it didn't fixed your initial issue with low performance. I will investigate it more.

Fuco1 commented 7 years ago

No, I think this was the source of the problem. Edebug or something errored and then emacs simply stopped responding. I will put the above debug declaration in dash and we'll see if it starts working.

Wilfred commented 7 years ago

Worryingly, -> is using the same debug declaration as thread-first. We can fix ->, but fixing upstream Emacs is harder (and wouldn't affect the current release).

sviridov commented 7 years ago

No, I think this was the source of the problem. Edebug or something errored and then emacs simply stopped responding. I will put the above debug declaration in dash and we'll see if it starts working.

Well, I tried it locally and I saw that even with fixed error there is no response from Emacs.

Fuco1 commented 7 years ago

I came up with this

(declare (debug (form &rest [&or symbolp (sexp &rest [&or "it" form])])))

We just need to tell it that it is a valid token in and of itself.

sviridov commented 7 years ago

I came up with this

Yep, just tested it, works fine for me.

Worryingly, -> was using the same debug declaration as thread-first. We can fix ->, but fixing upstream Emacs is harder (and wouldn't affect the current release).

I tried to edebug this function:

(defun test123 (x)
  (thread-first x (+ 2)))

It works for me, maybe it's because of arguments definition: (thread-first &rest FORMS). Not 100% sure. But anyway it works.

Fuco1 commented 7 years ago

So, these are my results

>% cask exec ert-runner           

Rewrap with: 
.............................................................................................................................................................................................

Ran 189 tests in 19.515 seconds

[14:47:27]+matus@herakleitos:~/.emacs.d/projects/smartparens
>% TRAVIS=true cask exec ert-runner

Rewrap with: 
.............................................................................................................................................................................................

Ran 189 tests in 246.080 seconds

Wrote /tmp/undercover_coveralls_report
Sending: report to coveralls.io
Sending: OK

So at least it works. The it issue was caused by dash and I think I've fixed it with the above. The slowness is tiresome but I can work with that.

undercover-el / undercover.el

Upload to coveralls takes ages #21