Getting unordered output for unbuffered channels

I inserted 2 values in a go channel and I can see the time of insertion as well.
1st value is entering before 2nd, always.
However, sometimes, the 2nd entry is listened 1st from the unbuffered channel.

Screenshot containing time of entry of process 1 and 3 in time:nanosecond -

As we can see that 3 got listened first at 293187th nanosecond
and then 1st got listened,
However 1st was inserted at 293313th nanosecond and 2nd at 293314th nanosecond

Can I see the code? Note that, getting the timestamp is not instant, and a lot of things can happen between getting time time and sending the item to the channels.


Listener code


Producer

Basically Producer and consumer are called in parallel, as they are In a different goroutine

Yes, and that’s why there is no guarantee about the ordering.
Based on the code you provided above, I’m guessing the producer code is something like this:

go func() {
   ....
   p.logCh <- process
   // it's actually possible that another goroutine send another 
   // process to p.logCh in different goroutine after the line above
   // and before the log.Printf line below
   log.Printf("<the_timestamp> <the_process_id> sent")
   ....
}

So, it’s possible that the flow of your program is something like this:

  1. in 1st nanosecond you created 2 goroutine, goroutine A and goroutine B
  2. in 2nd nanosecond, goroutine A send an item X to the channel
  3. in 3rd nanosecond, goroutine B send an item Y to the channel
  4. in 4th nanosecond, goroutine B log “4 Y ended and sent to channel”
  5. in 5th nanosecond, goroutine A log “5 X ended and sent to channel”

as a result, you will see that Y logged before X, but actually X is sent first before Y.

What’s the solution? Well, you should think that sending an item to a channel and logging the event as a single operation that should be atomic (can’t be overlapped with other operation). One way to do this is using mutex. Before sending an item to a channel, lock the mutex first, then log the event, then unlock the mutex.

It’s not this, I am asking about when I listen from the channel.
If you check the first screenshot, A should be listened first based on your explanation that A entered first and B second.
However the result is that, B was pulled out first from the channel and then A.

It’s not about the log, it’s about order in which they were consumed.

Basically,
A was sent to channel at 1 th nanosecond, and B at 2 th nanosecond.
However, B came out at 3 rd nanosecond and A at 4th

How do you know A sent to the channel at 1st nanosecond and B at 2nd nanosecond?

You can check my first screenshot,
1st process was sent and then 3rd, however 3rd came out before 1st from channel

Your screenshot doesn’t prove that the 1st process was sent before the 3rd one.
Again, check my explanation above; a lot of things can happen between sending an item to a channel and logging it. Your screenshot only proves that the log message from the 1st process appeared before the 3rd one, but it doesn’t prove that the items were sent in the same order.

Ok, are you implying that, there might be an ordering like -

  1. Process 3 sent to channel.
  2. Then go-compiler switched to another go-routine on which 1st process was sent to channel.
  3. Then the 1st process’s log was printed.
  4. Then go-compiler again switched to previous go-routine and 3rd process’s log was printed ?

Yup, that’s exactly what I meant in my reply above (Getting unordered output for unbuffered channels - #6 by jauhararifin)

  1. Then go-compiler switched to another go-routine on which 1st process was sent to channel.

Actually, it might not even be a context switch there if you have multiple threads in your Go program, and by default the number of threads in your go program is 2 times the number of cores you have in your CPU (I might be wrong about the exact number here). And note that thread is not the same as goroutine.

Yeah, the switching I mentioned is not context switching, it’s basically the go-compiler’s go-routine scheduling.
But got your point, thanks for the explanation.

Nit picking, FWIW. The go compiler has nothing to do with this. It’s the go runtime that schedules goroutines. The compiler’s job is finished once the code has been built. The goroutine scheduling is dynamic and may vary from run to run.

2 Likes

You are right, my bad.
Thanks for pointing out. :smiley:

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.