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.
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:
in 1st nanosecond you created 2 goroutine, goroutine A and goroutine B
in 2nd nanosecond, goroutine A send an item X to the channel
in 3rd nanosecond, goroutine B send an item Y to the channel
in 4th nanosecond, goroutine B log “4 Y ended and sent to channel”
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
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.
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.