unofficial mirror of guile-user@gnu.org 
 help / color / mirror / Atom feed
* Performance issue with guile-2.2
@ 2017-04-11 10:28 Vijay Pratap Chaurasia
  2017-04-11 14:22 ` Thomas Morley
  0 siblings, 1 reply; 7+ messages in thread
From: Vijay Pratap Chaurasia @ 2017-04-11 10:28 UTC (permalink / raw)
  To: guile-user; +Cc: Vijay Pratap Chaurasia

Hi,
     I have a tool which compares live data between two sources. I found
that the program runs more than 3 times slower than the same with
guile-2.0.11 . I have done profiling but there was nothing special to point
out. All most all calls were taking more than double the time compare to
guile-2.0.11. It is contrary to the claim of 30% performance boost with
guile-2.2 release. Can some one point the possible reason for slowness?

I have created a simple test program which reports the diff of two alist.

*time  /home/guile-2.2/bin/guile -s ./performanceTest.scm*
real    0m34.375s
user    0m37.616s
sys     0m0.361s

*time /home/guile-2.0/bin/guile -s ./performanceTest.scm*
real    0m18.939s
user    0m18.829s
sys     0m0.104s


*Test Code:*

*(use-modules (ice-9 eval-string)  (ice-9 common-list)  (ice-9 hash-table)
 *
*                     (srfi srfi-1)  (ice-9 rdelim))*

*(define *obj-string-cache* (make-hash-table 500))*
*(define (fast-obj-string obj)*
*  (let ((entry (hashq-ref *obj-string-cache* obj #f)))*
*    (unless entry*
*        (set! entry (if (symbol? obj) (symbol->string obj) (object->string
obj)))*
*        (hashq-set! *obj-string-cache* obj entry))*
*    entry))*

*(define (sort-tuples tuples)*
*  (sort-list tuples (lambda (x y) (string<? (fast-obj-string (car x))
(fast-obj-string (car y))))))*

*(define (report-diff type tuple1 tuple2)*
*  (let ((tuple (if tuple1 tuple1 tuple2)))*
*     (cond ((eq? type '-) `((- . (,tuple1))))*
*              ((eq? type '+) `((+ . (,tuple2))))*
*              ((eq? type '!) `((! . (,tuple1 . (,tuple2))))))))*

*(define (diff-sorted-tuples tuples1 tuples2 diff)*
*  (cond ((and (null? tuples1) (null? tuples2)) diff)*
*        ((null? tuples1) (append (map (lambda (x) (report-diff '+ #f x))
tuples2) diff))*
*        ((null? tuples2) (append (map (lambda (x) (report-diff '- x #f))
tuples1) diff))*
*        (else*
*         (let* ((tuple1 (car tuples1))*
*                (tuple2 (car tuples2)))*
*           (cond ((equal? (car tuple1) (car tuple2))*
*                  (diff-sorted-tuples (cdr tuples1) (cdr tuples2)*
*                                      (if (equal? tuple1 tuple2) diff
(append! diff (report-diff '! tuple1 tuple2)))))*
*                 ((string<? (fast-obj-string (car tuple1))*
*                            (fast-obj-string (car tuple2)))*
*                  (diff-sorted-tuples (cdr tuples1) tuples2 (append! diff
(report-diff '- tuple1 #f))))*
*                 (else*
*                  (diff-sorted-tuples tuples1 (cdr tuples2) (append! diff
(report-diff '+ #f tuple2)))))))))*

*(define-inlinable (diff-tuples tuples1 tuples2)*
*  (diff-sorted-tuples (sort-tuples tuples1) (sort-tuples tuples2) '()))*

*(define compare*
*  (let ((count 0))*
*     (lambda (port)*
*           (let ((msg  (eval-string (read-line port))))*
*               (diff-tuples msg msg)*
*               (seek port 0 SEEK_SET)*
*               (set! count (1+ count))*
*               (if (< count 10000) *
*                  (compare port))))))*

*(compare (open-input-file "data.txt"))*

*File data.txt*


*'(  (IDN_PROD_PERM 98) (RDNDISPLAY 120) (DSPLY_NAME "MINI GOLD JUN7")
(RDN_EXCHID 23) (TIMACT "2017-03-20 10:33:06") (FID_TRD_PRC 1235.2)
(FID_TRD_PREV1_PRC 1234.7) (FID_TRD_PREV2_PRC 1234.8) (TRDPRC_4 1234.7)
(TRDPRC_5 1234.7) (FID_NET_CHG 2.0) (FID_HI 1237.2) (FID_LO 1233.0)
(FID_TICK 1) (CURRENCY 840) (TRADE_DATE "3/20/2017") (ACTIV_DATE
"3/20/2017") (TRDTIM_1 "2017-03-20 10:17:32") (OPEN_PRC 1233.3)
(FID_YSET_PRC 1233.2) (FID_BID 1235.1) (FID_ASK 1235.6) (NEWS "YYYY")
(NEWS_TIME " 7:53:07") (FID_BID_SIZE 5) (FID_ASK_SIZE 1) (FID_CUM_VOL 30)
(CONTR_MNTH "JUN7") (BLKVOLUM null) (FID_SRC_PRC_FMT_CODE 1) (LOTSZUNITS
32) (FID_PCNT_CHG 0.16) (OPEN_BID 1220.7) (OPEN_ASK 1234.0) (CLOSE_BID
1231.4) (CLOSE_ASK 1232.9) (LOCHIGH 1365.3) (LOCLOW 1098.0) (FID_OPN_INT
165) (OPINTNC 23) (FID_EXPR "6/28/2017") (FID_SET_PRC 1233.2) (UPLIMIT
null) (LOLIMIT null) (FID_NO_OF_TRDS 26) (OFFCL_CODE "5050169")
(FID_IDN_HSTCLSDATE "3/17/2017") (LIMIT_IND null) (TURNOVER 32109.0)
(YCHIGH_IND null) (YCLOW_IND null) (DAYS_MAT 101) (PRC_QL_CD 160)
(TDY_UN_CLS null) (TDY_OF_CLS null) (FID_TRD_VOL 1) (LOT_SIZE_A 32.15)
(RECORDTYPE 178) (FID_SET_DATE "3/17/2017") (BID_TONE "i") (ASK_TONE "i")
(OPINT_2 142) (OPINT_DATE "3/17/2017") (IRGVOL null) (INSPRC null) (INSVOL
null) (FID_TRD_TIME "2017-03-20 10:17:32") (TNOVER_SC null) (HST_VOL null)
(EXERCISED null) (BCAST_REF "GOL") (HST_SESVOL 56) (ACT_FLAG1 "s")
(ACT_FLAG2 "s") (ACT_FLAG3 "b") (ACT_FLAG4 "b") (ACT_FLAG5 " ") (GEN_VAL1
1235.4) (GEN_VAL2 1.0) (GEN_VAL3 1233.4) (GEN_VAL4 101) (GV1_TEXT "SPLTrd")
(GV2_TEXT "SPLVol") (GV3_TEXT "SYS") (SEQNUM 52690211) (QUOTIM "2017-03-20
10:33:06") (GV1_DATE "3/20/2017") (GEN_VAL5 null) (GV1_TIME "2017-03-20
10:19:15") (EXCHTIM "2017-03-20 10:33:06") (CONV_FAC 0) (PREF_DISP 5391)
(VOL_X_PRC1 1234.96) (DSO_ID null) (BIG_VOL null) (RDN_EXCHD2 759)
(THEO_OPEN 1233.4) (LSTTRDDATE null) (OPINT_DAT2 "3/16/2017") (PREV_DISP
3491) (MPV null) (OFF_CLOSE null) (QUOTE_DATE "3/20/2017") (TRDVOL_2 1)
(TRDVOL_3 1) (TRDVOL_4 1) (TRDVOL_5 1) (VWAP 1234.96) (PROV_SYMB "5050169")
(BID_ASK_DT "3/17/2017") (ISIN_CODE null) (LST_TRD_PR 1232.1) (MNEMONIC
"YG") (UNDERLYING null) (PERIOD_CDE "O") (TRDTIM_MS 51452672) (SALTIM_MS
51452672) (QUOTIM_MS 52386000) )*


*Profile output comparison*

*GUILE 2.0.11*

*%     cumulative   self*

*time   seconds     seconds      name*

 62.15     11.87     11.87  read

  7.56      1.44      1.44  string<?

  6.91      3.55      1.32  #<procedure b60d8b0 at
./performanceTest1.scm:23:20 (x y)>

  6.51      1.24      1.24  %read-line

  5.86      2.23      1.12  fast-obj-string

  5.80      1.11      1.11  hashq-ref

  1.50      5.28      0.29  sort-list

  0.91      0.17      0.17  diff-sorted-tuples

  0.46      0.09      0.09  #<procedure b786438 at
ice-9/eval-string.scm:73:5 (port)>

  0.20     12.09      0.04  read-and-eval

  0.20      0.09      0.04  #<procedure aa992a0 at ice-9/boot-9.scm:2777:4
(name #:optional autoload version #:key ensure)>

  0.13     19.11      0.02  #<procedure b60d650 at
./performanceTest1.scm:56:5 (port)>

  0.13      0.09      0.02  scan

  0.13      0.05      0.02  nested-ref-module

  0.13      0.05      0.02  #<procedure b6ce410 at
language/scheme/spec.scm:34:16 (port env)>

  0.13      0.02      0.02  module-variable

  0.13      0.02      0.02  seek

  0.07     19.11      0.01  save-module-excursion

  0.07      1.26      0.01  read-line

  0.07      0.12      0.01  #<procedure aa39470 at ice-9/eval.scm:499:4
(exp)>

  0.07      0.10      0.01  expand-top-sequence

  0.07      0.06      0.01  lookup-language

  0.07      0.06      0.01  syntax-type

  0.07      0.02      0.01  module-ref-submodule

  0.07      0.01      0.01  #<procedure eeb2050>

  0.07      0.01      0.01  #<procedure aa93090 at ice-9/boot-9.scm:2004:2
(module)>

  0.07      0.01      0.01  #<procedure aadab00>

  0.07      0.01      0.01  variable-ref

  0.07      0.01      0.01  #<procedure d11b650>

  0.07      0.01      0.01  current-module

  0.07      0.01      0.01  assq

  0.07      0.01      0.01  #<procedure b591cf0 at ice-9/boot-9.scm:1380:4
(obj)>

  0.07      0.01      0.01  #<procedure b988120>

  0.07      0.01      0.01  memoize-expression

  0.07      0.01      0.01  #<procedure ba84230>

  0.00     19.11      0.00  eval

  0.00     19.11      0.00  load-compiled/vm

  0.00     19.11      0.00  #<procedure b60da20 ()>

  0.00     19.11      0.00  call-with-prompt

  0.00     19.11      0.00  #<procedure b584ce0 at ice-9/boot-9.scm:4045:3
()>

  0.00     12.27      0.00  call-with-input-string

  0.00      0.12      0.00  lp

  0.00      0.07      0.00  eval-string

  0.00      0.04      0.00  get-global-definition-hook

  0.00      0.01      0.00  #<procedure aa59280 at
ice-9/eval-string.scm:76:8 ()>

  0.00      0.01      0.00  module-ref

---

Sample count: 1535

Total time: 19.106 seconds (0.865 seconds in GC)

*GUILE 2.2*

*%     cumulative   self*

*time   seconds     seconds  procedure*

 35.62     13.04     13.02  read

 16.47     10.41      6.02  ./performanceTest1.scm:13:0:fast-obj-string

 12.06     14.82      4.41  ./performanceTest1.scm:23:20

 12.02      4.39      4.39  hashq-ref

  9.20      3.36      3.36  string<?

  5.64      2.10      2.06  %read-line

  5.12     36.54      1.87  ./performanceTest1.scm:56:5

  1.11      0.41      0.41  open-input-string

  0.96      0.35      0.35  ./performanceTest1.scm:34:0:diff-sorted-tuples

  0.19      0.07      0.07  %after-gc-thunk

  0.15     13.40      0.05  ice-9/eval-string.scm:33:0:read-and-eval

  0.15      0.05      0.05  module-variable

  0.11      0.07      0.04  ice-9/boot-9.scm:2485:0:nested-ref-module

  0.11      0.04      0.04  set-current-module

  0.07      0.09      0.03  ice-9/psyntax.scm:1083:10:parse

  0.07      0.07      0.03  language/scheme/spec.scm:34:16

  0.07      0.05      0.03  ice-9/eval-string.scm:77:8

  0.07      0.03      0.03  ice-9/psyntax.scm:2944:8:match

  0.04     50.02      0.01  ice-9/boot-9.scm:2306:0:save-module-excursion

  0.04     18.20      0.01  sort-list

  0.04      0.42      0.01  ice-9/ports.scm:526:0:call-with-input-string

  0.04      0.20      0.01  ice-9/eval.scm:40:0:primitive-eval

  0.04      0.18      0.01  ice-9/psyntax.scm:1054:6:expand-top-sequence

  0.04      0.12      0.01  ice-9/eval-string.scm:56:0:eval-string

  0.04      0.09      0.01  ice-9/boot-9.scm:2699:4

  0.04      0.07      0.01  ice-9/psyntax.scm:872:4:resolve-identifier

  0.04      0.05      0.01  ice-9/boot-9.scm:228:5:map1

  0.04      0.03      0.01  ice-9/boot-9.scm:2293:0:module-ref-submodule

  0.04      0.03      0.01  ice-9/eval-string.scm:28:0:ensure-language

  0.04      0.01      0.01  memq

  0.04      0.01      0.01  ice-9/boot-9.scm:1975:2

  0.04      0.01      0.01  ice-9/boot-9.scm:1293:2

  0.04      0.01      0.01  variable-ref

  0.04      0.01      0.01  list?

  0.04      0.01      0.01  ice-9/psyntax.scm:767:10:search

  0.04      0.01      0.01  ice-9/boot-9.scm:1371:17

  0.04      0.01      0.01  variable-bound?

  0.04      0.01      0.01  ice-9/boot-9.scm:1975:2

  0.04      0.01      0.01  ice-9/boot-9.scm:1306:4

  0.00     36.54      0.00  apply-smob/1

  0.00     36.54      0.00  ice-9/eval.scm:618:6

  0.00     36.54      0.00  ice-9/boot-9.scm:709:0:call-with-prompt

  0.00     36.54      0.00  ice-9/boot-9.scm:3821:3

  0.00     36.54      0.00  anon #xec651098

  0.00      2.10      0.00  ice-9/rdelim.scm:193:0:read-line

  0.00      0.14      0.00  ice-9/psyntax.scm:1289:6:syntax-type

  0.00      0.09      0.00  system/base/language.scm:61:0:lookup-language

  0.00      0.07      0.00  anon #xfce2f8

  0.00      0.03      0.00  ice-9/psyntax.scm:2043:19

  0.00      0.03      0.00  ice-9/psyntax.scm:2907:8:match*

  0.00      0.01      0.00  ice-9/psyntax.scm:1950:6:strip

  0.00      0.01      0.00  ice-9/boot-9.scm:223:2:map

  0.00      0.01      0.00  ice-9/psyntax.scm:762:6:id-var-name

  0.00      0.01      0.00  ice-9/eval-string.scm:66:9

  0.00      0.01      0.00  ice-9/psyntax.scm:2695:10:macroexpand

  0.00      0.01      0.00  ice-9/psyntax.scm:2046:26

  0.00      0.01      0.00  ice-9/boot-9.scm:2611:4

---

Sample count: 2695

Total time: 36.543 seconds (0.539 seconds in GC)



Thanks
- vijay


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: Performance issue with guile-2.2
  2017-04-11 10:28 Performance issue with guile-2.2 Vijay Pratap Chaurasia
@ 2017-04-11 14:22 ` Thomas Morley
  2017-04-11 15:51   ` Stefan Israelsson Tampe
                     ` (2 more replies)
  0 siblings, 3 replies; 7+ messages in thread
From: Thomas Morley @ 2017-04-11 14:22 UTC (permalink / raw)
  To: Vijay Pratap Chaurasia; +Cc: guile-user

[-- Attachment #1: Type: text/plain, Size: 1593 bytes --]

2017-04-11 12:28 GMT+02:00 Vijay Pratap Chaurasia <vijaypcin@gmail.com>:
> Hi,
>      I have a tool which compares live data between two sources. I found
> that the program runs more than 3 times slower than the same with
> guile-2.0.11 . I have done profiling but there was nothing special to point
> out. All most all calls were taking more than double the time compare to
> guile-2.0.11. It is contrary to the claim of 30% performance boost with
> guile-2.2 release. Can some one point the possible reason for slowness?
>
> I have created a simple test program which reports the diff of two alist.
>
> *time  /home/guile-2.2/bin/guile -s ./performanceTest.scm*
> real    0m34.375s
> user    0m37.616s
> sys     0m0.361s
>
> *time /home/guile-2.0/bin/guile -s ./performanceTest.scm*
> real    0m18.939s
> user    0m18.829s
> sys     0m0.104s
>

Hi vijay,

I'm from LilyPond, where we have our own problems with every
guile-2.x, we still use guile-1.8.
So I'm very interested in performance problems.

Though, I can't confirm your observations.
Admittedly I used 2.0.14, with this I get:

2.2.0.17-685ca (built from recent master)

real    0m31.642s
user    0m33.272s
sys     0m0.184s

2.0.14 (built from the released tarball)

real    1m39.361s
user    1m41.832s
sys     0m0.224s

Pity it doesn't work for guile-1.8...


One other thing, please attach your files, or at least teach your
e-mail-client not to insert *-signs at every line-break etc.
Regardless whether there should be a line-break or not.

Reformated versions are attached, if someone else want to check, too.

Cheers,
  Harm

[-- Attachment #2: data.txt --]
[-- Type: text/plain, Size: 2233 bytes --]

'(  (IDN_PROD_PERM 98) (RDNDISPLAY 120) (DSPLY_NAME "MINI GOLD JUN7") (RDN_EXCHID 23) (TIMACT "2017-03-20 10:33:06") (FID_TRD_PRC 1235.2) (FID_TRD_PREV1_PRC 1234.7) (FID_TRD_PREV2_PRC 1234.8) (TRDPRC_4 1234.7)(TRDPRC_5 1234.7) (FID_NET_CHG 2.0) (FID_HI 1237.2) (FID_LO 1233.0) (FID_TICK 1) (CURRENCY 840) (TRADE_DATE "3/20/2017") (ACTIV_DATE "3/20/2017") (TRDTIM_1 "2017-03-20 10:17:32") (OPEN_PRC 1233.3) (FID_YSET_PRC 1233.2) (FID_BID 1235.1) (FID_ASK 1235.6) (NEWS "YYYY") (NEWS_TIME " 7:53:07") (FID_BID_SIZE 5) (FID_ASK_SIZE 1) (FID_CUM_VOL 30) (CONTR_MNTH "JUN7") (BLKVOLUM null) (FID_SRC_PRC_FMT_CODE 1) (LOTSZUNITS 32) (FID_PCNT_CHG 0.16) (OPEN_BID 1220.7) (OPEN_ASK 1234.0) (CLOSE_BID 1231.4) (CLOSE_ASK 1232.9) (LOCHIGH 1365.3) (LOCLOW 1098.0) (FID_OPN_INT 165) (OPINTNC 23) (FID_EXPR "6/28/2017") (FID_SET_PRC 1233.2) (UPLIMIT null) (LOLIMIT null) (FID_NO_OF_TRDS 26) (OFFCL_CODE "5050169")(FID_IDN_HSTCLSDATE "3/17/2017") (LIMIT_IND null) (TURNOVER 32109.0)(YCHIGH_IND null) (YCLOW_IND null) (DAYS_MAT 101) (PRC_QL_CD 160) (TDY_UN_CLS null) (TDY_OF_CLS null) (FID_TRD_VOL 1) (LOT_SIZE_A 32.15) (RECORDTYPE 178) (FID_SET_DATE "3/17/2017") (BID_TONE "i") (ASK_TONE "i") (OPINT_2 142) (OPINT_DATE "3/17/2017") (IRGVOL null) (INSPRC null) (INSVOL null) (FID_TRD_TIME "2017-03-20 10:17:32") (TNOVER_SC null) (HST_VOL null) (EXERCISED null) (BCAST_REF "GOL") (HST_SESVOL 56) (ACT_FLAG1 "s") (ACT_FLAG2 "s") (ACT_FLAG3 "b") (ACT_FLAG4 "b") (ACT_FLAG5 " ") (GEN_VAL1 1235.4) (GEN_VAL2 1.0) (GEN_VAL3 1233.4) (GEN_VAL4 101) (GV1_TEXT "SPLTrd") (GV2_TEXT "SPLVol") (GV3_TEXT "SYS") (SEQNUM 52690211) (QUOTIM "2017-03-20 10:33:06") (GV1_DATE "3/20/2017") (GEN_VAL5 null) (GV1_TIME "2017-03-20 10:19:15") (EXCHTIM "2017-03-20 10:33:06") (CONV_FAC 0) (PREF_DISP 5391) (VOL_X_PRC1 1234.96) (DSO_ID null) (BIG_VOL null) (RDN_EXCHD2 759) (THEO_OPEN 1233.4) (LSTTRDDATE null) (OPINT_DAT2 "3/16/2017") (PREV_DISP 3491) (MPV null) (OFF_CLOSE null) (QUOTE_DATE "3/20/2017") (TRDVOL_2 1) (TRDVOL_3 1) (TRDVOL_4 1) (TRDVOL_5 1) (VWAP 1234.96) (PROV_SYMB "5050169") (BID_ASK_DT "3/17/2017") (ISIN_CODE null) (LST_TRD_PR 1232.1) (MNEMONIC "YG") (UNDERLYING null) (PERIOD_CDE "O") (TRDTIM_MS 51452672) (SALTIM_MS 51452672) (QUOTIM_MS 52386000) )

[-- Attachment #3: performanceTest.scm --]
[-- Type: text/x-scheme, Size: 2265 bytes --]

(use-modules
     (ice-9 eval-string)
     (ice-9 common-list)
     (ice-9 hash-table)
     (srfi srfi-1)
     (ice-9 rdelim))


(define *obj-string-cache* (make-hash-table 500))
(define (fast-obj-string obj)
  (let ((entry (hashq-ref *obj-string-cache* obj #f)))
    (unless entry
        (set! entry (if (symbol? obj) (symbol->string obj) (object->string obj)))
        (hashq-set! *obj-string-cache* obj entry))
    entry))

(define (sort-tuples tuples)
  (sort-list tuples
      (lambda (x y)
          (string<? (fast-obj-string (car x))
                    (fast-obj-string (car y))))))

(define (report-diff type tuple1 tuple2)
  (let ((tuple (if tuple1 tuple1 tuple2)))
     (cond ((eq? type '-) `((- . (,tuple1))))
              ((eq? type '+) `((+ . (,tuple2))))
              ((eq? type '!) `((! . (,tuple1 . (,tuple2))))))))

(define (diff-sorted-tuples tuples1 tuples2 diff)
  (cond ((and (null? tuples1) (null? tuples2)) diff)
        ((null? tuples1) (append (map (lambda (x) (report-diff '+ #f x)) tuples2) diff))
        ((null? tuples2) (append (map (lambda (x) (report-diff '- x #f)) tuples1) diff))
        (else
         (let* ((tuple1 (car tuples1))
                (tuple2 (car tuples2)))
           (cond ((equal? (car tuple1) (car tuple2))
                  (diff-sorted-tuples (cdr tuples1) (cdr tuples2)
                                      (if (equal? tuple1 tuple2) diff (append! diff (report-diff '! tuple1 tuple2)))))
                 ((string<? (fast-obj-string (car tuple1))
                            (fast-obj-string (car tuple2)))
                  (diff-sorted-tuples (cdr tuples1) tuples2 (append! diff (report-diff '- tuple1 #f))))
                 (else
                  (diff-sorted-tuples tuples1 (cdr tuples2) (append! diff (report-diff '+ #f tuple2)))))))))

(define-inlinable (diff-tuples tuples1 tuples2)
  (diff-sorted-tuples (sort-tuples tuples1) (sort-tuples tuples2) '()))

(define compare
  (let ((count 0))
     (lambda (port)
           (let ((msg  (eval-string (read-line port))))
               (diff-tuples msg msg)
               (seek port 0 SEEK_SET)
               (set! count (1+ count))
               (if (< count 10000)
                  (compare port))))))

(compare (open-input-file "data.txt"))

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: Performance issue with guile-2.2
  2017-04-11 14:22 ` Thomas Morley
@ 2017-04-11 15:51   ` Stefan Israelsson Tampe
  2017-04-12  6:45   ` Vladimir Zhbanov
  2017-04-12  7:28   ` Vijay Pratap Chaurasia
  2 siblings, 0 replies; 7+ messages in thread
From: Stefan Israelsson Tampe @ 2017-04-11 15:51 UTC (permalink / raw)
  To: Thomas Morley; +Cc: guile-user@gnu.org

Hi Thomas!

Have the lilipond team retried benchmarks with the newly released guile
2.2? One of the most resent improvements was fixing a gc issue that caused
performance issues with files of large scale. Could be, with some luck,
that that fix helped the lilypond benchmark that underperforms as well.

On Tue, Apr 11, 2017 at 4:22 PM, Thomas Morley <thomasmorley65@gmail.com>
wrote:

> 2017-04-11 12:28 GMT+02:00 Vijay Pratap Chaurasia <vijaypcin@gmail.com>:
> > Hi,
> >      I have a tool which compares live data between two sources. I found
> > that the program runs more than 3 times slower than the same with
> > guile-2.0.11 . I have done profiling but there was nothing special to
> point
> > out. All most all calls were taking more than double the time compare to
> > guile-2.0.11. It is contrary to the claim of 30% performance boost with
> > guile-2.2 release. Can some one point the possible reason for slowness?
> >
> > I have created a simple test program which reports the diff of two alist.
> >
> > *time  /home/guile-2.2/bin/guile -s ./performanceTest.scm*
> > real    0m34.375s
> > user    0m37.616s
> > sys     0m0.361s
> >
> > *time /home/guile-2.0/bin/guile -s ./performanceTest.scm*
> > real    0m18.939s
> > user    0m18.829s
> > sys     0m0.104s
> >
>
> Hi vijay,
>
> I'm from LilyPond, where we have our own problems with every
> guile-2.x, we still use guile-1.8.
> So I'm very interested in performance problems.
>
> Though, I can't confirm your observations.
> Admittedly I used 2.0.14, with this I get:
>
> 2.2.0.17-685ca (built from recent master)
>
> real    0m31.642s
> user    0m33.272s
> sys     0m0.184s
>
> 2.0.14 (built from the released tarball)
>
> real    1m39.361s
> user    1m41.832s
> sys     0m0.224s
>
> Pity it doesn't work for guile-1.8...
>
>
> One other thing, please attach your files, or at least teach your
> e-mail-client not to insert *-signs at every line-break etc.
> Regardless whether there should be a line-break or not.
>
> Reformated versions are attached, if someone else want to check, too.
>
> Cheers,
>   Harm
>


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: Performance issue with guile-2.2
  2017-04-11 14:22 ` Thomas Morley
  2017-04-11 15:51   ` Stefan Israelsson Tampe
@ 2017-04-12  6:45   ` Vladimir Zhbanov
  2017-04-13 12:30     ` Ludovic Courtès
  2017-04-12  7:28   ` Vijay Pratap Chaurasia
  2 siblings, 1 reply; 7+ messages in thread
From: Vladimir Zhbanov @ 2017-04-12  6:45 UTC (permalink / raw)
  To: guile-user

Hi,

On 4/11/17, Thomas Morley <thomasmorley65@gmail.com> wrote:
...
> Reformated versions are attached, if someone else want to check, too.

Thank you for those.

Results on my machine are as follows:

Guile 2.2:
================================8<================================
$ /usr/local/bin/guile --version
guile (GNU Guile) 2.2.0

$ time /usr/local/bin/guile -s performancetest.scm
... /* compilation messages */

real    0m50.935s
user    0m46.920s
sys     0m0.152s

$ time /usr/local/bin/guile -s performancetest.scm

real    0m35.920s
user    0m36.928s
sys     0m0.112s

================================>8================================


Guile 2.0:
================================8<================================
$ guile-2.0 --version
guile (GNU Guile) 2.0.13

$ time guile-2.0 -s performancetest.scm
... /* compilation messages */

real    1m33.731s
user    1m33.584s
sys     0m0.116s

$ time guile-2.0 -s performancetest.scm

real    1m32.270s
user    1m33.164s
sys     0m0.140s
================================>8================================

Apparently, 2.2 performs better, especially after compilation.

  Vladimir



^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: Performance issue with guile-2.2
  2017-04-11 14:22 ` Thomas Morley
  2017-04-11 15:51   ` Stefan Israelsson Tampe
  2017-04-12  6:45   ` Vladimir Zhbanov
@ 2017-04-12  7:28   ` Vijay Pratap Chaurasia
  2017-04-14 11:13     ` Andy Wingo
  2 siblings, 1 reply; 7+ messages in thread
From: Vijay Pratap Chaurasia @ 2017-04-12  7:28 UTC (permalink / raw)
  To: Thomas Morley; +Cc: guile-user

Hi Thomas,
    Thanks for input and putting the code as attachment. I am consistently
getting bad performance with guile.2.2 even through it is reasonably good
with guile2.1 compare to guile2.0 . I have built guile on RHEL5 platform
using gcc4.4 with large file support (CFLAGS='-D_FILE_OFFSET_BITS=64
-D_LARGEFILE64_SOURCE -D_LARGEFILE_SOURCE') .
I will give a try with recent guile2.2 master and update.

$ export GUILE_LOAD_PATH=/home/guile.2.0.11/share; export
GUILE_LOAD_COMPILED_PATH=/home/guile.2.0.11/lib/guile/2.0/ccache; time
/home/guile.2.0.11/bin/guile -s ./performanceTest.scm
real    0m17.034s
user    0m16.964s
sys     0m0.033s

$ export GUILE_LOAD_PATH=/home/guile.git.20141208/share; export
GUILE_LOAD_COMPILED_PATH=/home/guile.git.20141208/lib/guile/2.2/ccache;
time /home/guile.git.20141208/bin/guile -s ./performanceTest.scm
real    0m15.370s
user    0m15.385s
sys     0m0.043s

$ export GUILE_LOAD_PATH=/home/guile-2.2/share; export
GUILE_LOAD_COMPILED_PATH=/home/guile-2.2/lib/guile/2.2/ccache; time
/home/guile-2.2/bin/guile -s ./performanceTest.scm
real    0m34.904s
user    0m38.178s
sys     0m0.352s


Thanks
Vijay

On Tue, Apr 11, 2017 at 7:52 PM, Thomas Morley <thomasmorley65@gmail.com>
wrote:

> 2017-04-11 12:28 GMT+02:00 Vijay Pratap Chaurasia <vijaypcin@gmail.com>:
> > Hi,
> >      I have a tool which compares live data between two sources. I found
> > that the program runs more than 3 times slower than the same with
> > guile-2.0.11 . I have done profiling but there was nothing special to
> point
> > out. All most all calls were taking more than double the time compare to
> > guile-2.0.11. It is contrary to the claim of 30% performance boost with
> > guile-2.2 release. Can some one point the possible reason for slowness?
> >
> > I have created a simple test program which reports the diff of two alist.
> >
> > *time  /home/guile-2.2/bin/guile -s ./performanceTest.scm*
> > real    0m34.375s
> > user    0m37.616s
> > sys     0m0.361s
> >
> > *time /home/guile-2.0/bin/guile -s ./performanceTest.scm*
> > real    0m18.939s
> > user    0m18.829s
> > sys     0m0.104s
> >
>
> Hi vijay,
>
> I'm from LilyPond, where we have our own problems with every
> guile-2.x, we still use guile-1.8.
> So I'm very interested in performance problems.
>
> Though, I can't confirm your observations.
> Admittedly I used 2.0.14, with this I get:
>
> 2.2.0.17-685ca (built from recent master)
>
> real    0m31.642s
> user    0m33.272s
> sys     0m0.184s
>
> 2.0.14 (built from the released tarball)
>
> real    1m39.361s
> user    1m41.832s
> sys     0m0.224s
>
> Pity it doesn't work for guile-1.8...
>
>
> One other thing, please attach your files, or at least teach your
> e-mail-client not to insert *-signs at every line-break etc.
> Regardless whether there should be a line-break or not.
>
> Reformated versions are attached, if someone else want to check, too.
>
> Cheers,
>   Harm
>



-- 
- vijay


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: Performance issue with guile-2.2
  2017-04-12  6:45   ` Vladimir Zhbanov
@ 2017-04-13 12:30     ` Ludovic Courtès
  0 siblings, 0 replies; 7+ messages in thread
From: Ludovic Courtès @ 2017-04-13 12:30 UTC (permalink / raw)
  To: guile-user

Hi,

Vladimir Zhbanov <vzhbanov@gmail.com> skribis:

> Results on my machine are as follows:
>
> Guile 2.2:

[...]

> $ time /usr/local/bin/guile -s performancetest.scm
>
> real    0m35.920s
> user    0m36.928s
> sys     0m0.112s
>
> ================================>8================================
>
>
> Guile 2.0:

[...]

> $ time guile-2.0 -s performancetest.scm
>
> real    1m32.270s
> user    1m33.164s
> sys     0m0.140s
> ================================>8================================
>
> Apparently, 2.2 performs better, especially after compilation.

So 2.2 is three times faster than 2.0, right?  That sounds like good
news.  :-)

Note that if you’re looking for performance, you definitely need to
compile the code beforehand, both with 2.0 and 2.2.

Ludo’.




^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: Performance issue with guile-2.2
  2017-04-12  7:28   ` Vijay Pratap Chaurasia
@ 2017-04-14 11:13     ` Andy Wingo
  0 siblings, 0 replies; 7+ messages in thread
From: Andy Wingo @ 2017-04-14 11:13 UTC (permalink / raw)
  To: Vijay Pratap Chaurasia; +Cc: guile-user

On Wed 12 Apr 2017 09:28, Vijay Pratap Chaurasia <vijaypcin@gmail.com> writes:

>     Thanks for input and putting the code as attachment. I am consistently
> getting bad performance with guile.2.2 even through it is reasonably good
> with guile2.1 compare to guile2.0 . I have built guile on RHEL5 platform
> using gcc4.4 with large file support (CFLAGS='-D_FILE_OFFSET_BITS=64
> -D_LARGEFILE64_SOURCE -D_LARGEFILE_SOURCE') .

This will implicitly disable optimizations, I think.  If you set CFLAGS,
you will need to add "-g -O2" to the CFLAGS.  You can rebuild just in
libguile/; the .go files are fine and don't need any rebuild.  Could
this be the issue?

GCC 4.4 is of course a very old compiler, but you probably know that :)

Andy



^ permalink raw reply	[flat|nested] 7+ messages in thread

end of thread, other threads:[~2017-04-14 11:13 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-04-11 10:28 Performance issue with guile-2.2 Vijay Pratap Chaurasia
2017-04-11 14:22 ` Thomas Morley
2017-04-11 15:51   ` Stefan Israelsson Tampe
2017-04-12  6:45   ` Vladimir Zhbanov
2017-04-13 12:30     ` Ludovic Courtès
2017-04-12  7:28   ` Vijay Pratap Chaurasia
2017-04-14 11:13     ` Andy Wingo

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).