goroutines affect each other when printing timecost

Question

I'm a freshman for Golang. I know goroutine is an abstract group of cpu and memory to run a piece of code.

So When I run some computing funcs(like sort) in goroutines, I'm hoping they run parallel. But the printed result seems weird, the "paralell" codes print nearly the same timecost.

Why? Is there something I missed about goroutine, or it's because of the func printTime() ?

codes: https://play.golang.org/p/n9DLn57ftM

P.S. codes should be copied to local go file and run. Those run in play.golang has some limitation.

the result is:

MaxProcs: 8

Source : 2.0001ms
Quick sort : 3.0002ms
Merge sort : 8.0004ms
Insertion sort : 929.0532ms
Goroutine num: 1

Source : 2.0001ms
Goroutine num: 4

Insertion sort : 927.0531ms
Quick sort : 930.0532ms
Merge sort : 934.0535ms

score 1 · Accepted Answer · answered Jun 29 '17 at 06:28

You should measure total time cost instead of individual time cost required by each sorting algorithm. The individual time cost might be longer when the task is distributed into several goroutines since it need additional time to setup the goroutine. Depending on the nature of your program, additional time might be needed for communication between goroutine and/or with main process. There're some resources related to goroutine, e.g.

If you change main function to:

func main() {
    fmt.Println("MaxProcs:", runtime.GOMAXPROCS(0)) // 8

    start := time.Now()
    sequentialTest()
    seq := time.Now()
    concurrentTest()
    con := time.Now()

    fmt.Printf("\n\nCalculation time, sequential: %v, concurrent: %v\n",
        seq.Sub(start), con.Sub(seq))
}

the output will look like:

MaxProcs: 4

Source : 3.0037ms
Quick sort : 5.0034ms
Merge sort : 13.0069ms
Insertion sort : 1.2590941s
Goroutine num: 1

Source : 3.0015ms
Goroutine num: 4

Insertion sort : 1.2399076s
Quick sort : 1.2459121s
Merge sort : 1.2519156s

Calculation time, sequential: 1.2831112s, concurrent: 1.2559194s

After removing printTime, it looks like:

MaxProcs: 4
Goroutine num: 1
Goroutine num: 4

Calculation time, sequential: 1.3154314s, concurrent: 1.244112s

The time cost value might change slightly, but most of the time the result will be sequential > concurrent. In summary, distributing the task into several goroutines, may increase the overall performance (time cost) but not the individual task.

score 0 · Answer 2 · answered Jun 29 '17 at 04:33

Sorry, I don't understand what you want to test. At the first, you code doesn't work for quickSort because you run quickSort with go quickSort(...).

wg.Add(1)
go func(){
    go quickSort(s1, nil)
    wg.Done()
}()

This goroutine will quit immediately. Now, I tested your code. And I notice that you must get total time between start and all of finish.

https://play.golang.org/p/O8Gj-OYIdR

score 0 · Answer 3 · answered Jun 29 '17 at 05:07

wg.Add(1)
go func(){
    go quickSort(s1, nil)
    wg.Done()
}()

You don't need that second go

It should be like

wg.Add(1)
go func(){
    quickSort(s1, nil)
    wg.Done()
}()

What happened is that go func() started one goroutine, and go quickSort(s1, nil) starts another. As a result, wg.Done() (and, as a result, wg.Done()) gets executed practically right away (without waiting for quickSort).

goroutines affect each other when printing timecost

3 Answers3