0

I'm trying to implement a producer/consumer class in Swift 2 using threads and NSCondition. So far I've come up with this code:

import Foundation

class ProducterConsumer {

    private let numberOfProducts = 1000
    private var products: [Int] = []
    private var condition = NSCondition()

    private func producer() {
        for var i = 0; i < numberOfProducts; ++i {
            condition.lock()
            products.append(i)
            condition.broadcast()
            condition.unlock()
        }
    }

    private func consumer(id: Int) {
        while true {
            condition.lock()
            while products.count == 0 {
                condition.wait()
            }
            let product = products.popLast()!
            print("[\(id)] takes \(product)")
            condition.unlock()
        }
    }

    func runAndWait() {
        let queue = NSOperationQueue()
        for var i = 0; i < 2; ++i {
            queue.addOperationWithBlock {
                self.consumer(i)
            }
        }
        queue.addOperationWithBlock {
            self.producer()
        }
        queue.waitUntilAllOperationsAreFinished()
    }

}

let pc = ProducterConsumer()
pc.runAndWait()

Basically I'm using operation queues to create 3 new threads: 1 producer that fills a shared array of Int (from 0 to 1000) and 2 consumers that pop the values and display them.

The results show that only consumer thread #0 "works" and seems to be poping values. I can't figure out why the consumer thread #1 won't show in the console. I'm expecting a more or less 50% working times between the two consumers. What I am missing?

[0] takes 0
[0] takes 1
...
[0] takes 998
[0] takes 999

Thank you!

Nicolas B.
  • 1,318
  • 1
  • 11
  • 20
  • I copy-pasted your code in a playground and everything looks fine to me: Sometimes [0] and sometimes [1] gets printed.. Maybe it's because the playground is actually quiet slow in executing and your threads just do it all in one swoop in a normal project. Maybe try a bigger number – Kametrixom Nov 09 '15 at 13:38
  • This is not my core competency, but I guess you should invoke condition.broadcast() or .signal() within each loop of consumer(). Otherwise you would never wake up the thread running in parallel. On the other hand there is not much time nor processing between the condition.unlock() and the condition.lock() statements within the while true loop. – Hermann Klecker Nov 09 '15 at 13:38
  • @Hermann Klecker From my point of view, consumers should never wall `broadcast` or `signal` since they are acting as passive workers. The producer only care about adding data and notifying everyone that new data is available. Consumers can only be woken up by the single producer to process these data. Why should consumers signal each other? – Nicolas B. Nov 09 '15 at 13:43
  • @Kametrixom I was suspecting something like that. It may be due to the fact that my scheduler is only running thread 0. But that wouldn't mean thread 1 allowed to run - OR - there's a kind of deadlock/race condition that forces only thread 0 to run. I don't know that yet. – Nicolas B. Nov 09 '15 at 13:46
  • Because the consumer does change the state of the products. That isn't exactly passive. – Hermann Klecker Nov 09 '15 at 13:46
  • I meant passive in the sense that they cannot work unless they are told to do so or new data is available. – Nicolas B. Nov 09 '15 at 13:48
  • Well then, give them a chance. As you don't really process the product taken from the stack you could at least consider the print statement as some processing. Try unlocking the condition before you print the line. Or what is the point in having two processes running in parallel when one (regardless which one) is always wating for the other one? The only processing that you can do in parallel here is the 'while true' statment, just the one, not the body of the loop. – Hermann Klecker Nov 09 '15 at 14:08
  • Well, that does seem to have an effect! I can see both threads working now (lots of [0] then only [1]). Still not what I was hoping ([0] and [1] intertwined) but that is definitely a start! Can you elaborate on what happened? Thanks! – Nicolas B. Nov 09 '15 at 14:16
  • I would love to, but to be frank, as mentioned, this is not exacly my core competence. I was just thinking about and transferring a bit of my limited experience with multi tasking from C++ and Java. I can only summarize my guts' feeling so "You need to give the OS at least a chance to manage the tasks between each unlocking and the next locking statment." – Hermann Klecker Nov 09 '15 at 16:02
  • Well thank you for your help. That makes sense. – Nicolas B. Nov 09 '15 at 19:05
  • Just curious: why do you use a Producer/Consumer pattern? This has several drawbacks, like blocking semantics (uses and halts threads), difficult to cancel (since a thread is blocked), performance issues (e.g. "cache thrashing, etc.). Wouldn't it be possible to approach the problem differently, and find a solution with GCD? – CouchDeveloper Nov 09 '15 at 20:34
  • This is just a test from my perspective to manipulate NSCondition. Would love to hear your recommendations/implementation with GCD though. Cheers. – Nicolas B. Nov 09 '15 at 20:37

2 Answers2

1

The problem seems to be that a lazy var is not thread-safe, and your code even crashed in my test, with error message like

*** -[NSCondition dealloc]: condition (<NSCondition: 0x10080b310> '(null)') deallocated while still in use
*** Break on _NSLockError() to debug.
*** -[NSCondition wait]: condition (<NSCondition: 0x100e00920> '(null)') not locked
*** -[NSCondition unlock]: condition (<NSCondition: 0x100e00920> '(null)') unlocked from thread which did not lock it

As you can see, there are (at least) two different NSCondition instances.

If you change the property to

private var condition = NSCondition()

then a single condition variable is created when the ProducterConsumer() instance is created, and everything runs as expected.

Another problem is that in

for var i = 0; i < 2; ++i {
    queue.addOperationWithBlock {
        self.consumer(i)
    }
}

the block captures the variable i by reference. Therefore even different running threads can report the same number i. To capture the variable by value, use an explicit capture list:

for var i = 0; i < 5; ++i {
    queue.addOperationWithBlock { [i] in
        self.consumer(i)
    }
}

I would also recommend to use NSLog() for debug output in a multi-threaded program because

  • NSLog() is thread-safe in contrast to print(), and
  • NSLog() prints both the process id and a thread id, so that you can verify if the output comes from different threads. For example:

    2015-11-09 15:21:43.711 MyProgram[8569:537106] [0] takes 19
    2015-11-09 15:21:43.788 MyProgram[8569:537108] [2] takes 18
    
Community
  • 1
  • 1
Martin R
  • 529,903
  • 94
  • 1,240
  • 1,382
  • Whaa, didn't know that. I've removed the `lazy` part but the console still shows only activity for thread #0 or #thread1 not both. – Nicolas B. Nov 09 '15 at 13:56
  • @NicolasB.: Actually I could see that now as well *sometimes* when running the program repeatedly. – But thinking about it again, I am not sure if there are any guarantees that condition signals are distributed "evenly". And usually it would not matter. Any consumer which is ready can take the next load of work. – Martin R Nov 09 '15 at 14:06
  • Gosh, I've been launching the program for a hundred times now and still haven't seen a run where both threads work. How depressing. – Nicolas B. Nov 09 '15 at 14:08
  • @NicolasB.: The problem could be something completely different! Try `queue.addOperationWithBlock { [i] in self.consumer(i) }` for starting the consumer threads (`[i]` is a "capture list") ... Compare http://stackoverflow.com/questions/31565832/pass-value-to-closure. – Martin R Nov 09 '15 at 14:10
  • Thanks; that is definitely going to help but still no fair scheduling :) – Nicolas B. Nov 09 '15 at 14:24
  • @NicolasB.: Did you verify with NSLog() that really only one thread is doing all the work? What happens if you add `NSThread.sleepForTimeInterval(0.1)` to the consumer thread? – Martin R Nov 09 '15 at 14:32
  • Yup works as expected with the `sleep` call. What's going on? – Nicolas B. Nov 09 '15 at 15:24
  • @NicolasB.: I think that Hermann was on the right track with his comments. In your code, when a consumer thread releases the lock, the same thread is immediately waiting for the lock again. There is no automatic distribution, any waiting thread can get the lock. In a real application, a consumer thread would wait on the lock, retrieve an object from the queue, release the lock *and then do some work* before waiting again. – Martin R Nov 09 '15 at 16:06
  • So my code is good, but I'm not letting threads enough time to process data and thus opportunities for other threads to work? – Nicolas B. Nov 09 '15 at 19:01
  • this is only partially true. check my example below. the producer was running really fast and consumers slow. see the result ... – user3441734 Nov 09 '15 at 19:48
  • @NicolasB.: Your code looks good to me and it should work as expected if the consumer threads really do some work. But in your test code, as soon as the consumer thread releases the lock, it immediately waits again together with all other consumer threads. So any thread can acquire the lock, including the one that just released it. – Martin R Nov 09 '15 at 20:17
0

i slightly modify your consumer block (NSOperation)

private func consumer(id: Int) {
        while true {
            condition.lock()
            while products.count == 0 {
                condition.wait()
            }
            let product = products.popLast()!
            condition.unlock()
            NSLog("[\(id)] takes \(product)")
            usleep(500000)
        }
    }

check what is reported by NSLog

2015-11-09 20:26:06.249 Untitled Page 10[90128:4829072] [0] takes 0
2015-11-09 20:26:06.262 Untitled Page 10[90128:4829076] [1] takes 1
2015-11-09 20:26:06.760 Untitled Page 10[90128:4829072] [0] takes 9
2015-11-09 20:26:06.783 Untitled Page 10[90128:4829076] [1] takes 8
2015-11-09 20:26:07.272 Untitled Page 10[90128:4829072] [0] takes 7
2015-11-09 20:26:07.295 Untitled Page 10[90128:4829076] [1] takes 6
2015-11-09 20:26:07.775 Untitled Page 10[90128:4829072] [0] takes 5
2015-11-09 20:26:07.803 Untitled Page 10[90128:4829076] [1] takes 4
2015-11-09 20:26:08.282 Untitled Page 10[90128:4829072] [0] takes 3
2015-11-09 20:26:08.311 Untitled Page 10[90128:4829076] [1] takes 2

especially the order of values consumes by consumers.

NSCondition object acts as both a lock and a checkpoint in a given thread.

you should never rely on queue semantics to ensure a specific execution order of operation objects

number of products 100 number of consumers 20 no delays

2015-11-09 21:16:04.687 Untitled Page 10[90457:4863959] [0] takes 0
2015-11-09 21:16:04.692 Untitled Page 10[90457:4863915] [1] takes 1
2015-11-09 21:16:04.695 Untitled Page 10[90457:4863916] [2] takes 2
2015-11-09 21:16:04.713 Untitled Page 10[90457:4863966] [3] takes 3
2015-11-09 21:16:04.720 Untitled Page 10[90457:4863915] [1] takes 4
2015-11-09 21:16:04.745 Untitled Page 10[90457:4863915] [1] takes 5
2015-11-09 21:16:04.754 Untitled Page 10[90457:4863915] [1] takes 6
2015-11-09 21:16:04.758 Untitled Page 10[90457:4863915] [1] takes 7
2015-11-09 21:16:04.761 Untitled Page 10[90457:4863915] [1] takes 8
2015-11-09 21:16:04.780 Untitled Page 10[90457:4863915] [1] takes 9
2015-11-09 21:16:04.788 Untitled Page 10[90457:4863915] [1] takes 10
2015-11-09 21:16:04.795 Untitled Page 10[90457:4863915] [1] takes 11
2015-11-09 21:16:04.800 Untitled Page 10[90457:4863915] [1] takes 12
2015-11-09 21:16:04.805 Untitled Page 10[90457:4863915] [1] takes 13
2015-11-09 21:16:04.812 Untitled Page 10[90457:4863925] [14] takes 14
2015-11-09 21:16:04.816 Untitled Page 10[90457:4863925] [14] takes 15
2015-11-09 21:16:04.823 Untitled Page 10[90457:4863979] [16] takes 16
2015-11-09 21:16:04.828 Untitled Page 10[90457:4863979] [16] takes 17
2015-11-09 21:16:04.833 Untitled Page 10[90457:4863980] [18] takes 18
2015-11-09 21:16:04.838 Untitled Page 10[90457:4863980] [18] takes 19
2015-11-09 21:16:04.843 Untitled Page 10[90457:4863980] [18] takes 20
2015-11-09 21:16:04.847 Untitled Page 10[90457:4863980] [18] takes 21
2015-11-09 21:16:04.853 Untitled Page 10[90457:4863966] [3] takes 22
2015-11-09 21:16:04.860 Untitled Page 10[90457:4863967] [4] takes 23
2015-11-09 21:16:04.866 Untitled Page 10[90457:4863967] [4] takes 24
2015-11-09 21:16:04.871 Untitled Page 10[90457:4863967] [4] takes 25
2015-11-09 21:16:04.877 Untitled Page 10[90457:4863967] [4] takes 26
2015-11-09 21:16:04.882 Untitled Page 10[90457:4863967] [4] takes 27
2015-11-09 21:16:04.887 Untitled Page 10[90457:4863967] [4] takes 28
2015-11-09 21:16:04.893 Untitled Page 10[90457:4863973] [10] takes 29
2015-11-09 21:16:04.900 Untitled Page 10[90457:4863974] [11] takes 30
2015-11-09 21:16:04.906 Untitled Page 10[90457:4863975] [12] takes 31
2015-11-09 21:16:04.911 Untitled Page 10[90457:4863976] [13] takes 32
2015-11-09 21:16:04.916 Untitled Page 10[90457:4863976] [13] takes 33
2015-11-09 21:16:04.921 Untitled Page 10[90457:4863926] [15] takes 34
2015-11-09 21:16:04.927 Untitled Page 10[90457:4863926] [15] takes 35
2015-11-09 21:16:04.932 Untitled Page 10[90457:4863926] [15] takes 36
2015-11-09 21:16:04.936 Untitled Page 10[90457:4863979] [16] takes 37
2015-11-09 21:16:04.939 Untitled Page 10[90457:4863981] [19] takes 38
2015-11-09 21:16:04.947 Untitled Page 10[90457:4863981] [19] takes 39
2015-11-09 21:16:04.953 Untitled Page 10[90457:4863916] [2] takes 40
2015-11-09 21:16:04.956 Untitled Page 10[90457:4863980] [18] takes 41
2015-11-09 21:16:04.962 Untitled Page 10[90457:4863966] [3] takes 42
2015-11-09 21:16:04.970 Untitled Page 10[90457:4863966] [3] takes 43
2015-11-09 21:16:04.974 Untitled Page 10[90457:4863969] [6] takes 44
2015-11-09 21:16:04.978 Untitled Page 10[90457:4863969] [6] takes 45
2015-11-09 21:16:04.983 Untitled Page 10[90457:4863969] [6] takes 46
2015-11-09 21:16:04.987 Untitled Page 10[90457:4863969] [6] takes 47
2015-11-09 21:16:04.994 Untitled Page 10[90457:4863969] [6] takes 48
2015-11-09 21:16:04.999 Untitled Page 10[90457:4863973] [10] takes 49
2015-11-09 21:16:05.005 Untitled Page 10[90457:4863973] [10] takes 50
2015-11-09 21:16:05.012 Untitled Page 10[90457:4863973] [10] takes 51
2015-11-09 21:16:05.020 Untitled Page 10[90457:4863973] [10] takes 52
2015-11-09 21:16:05.026 Untitled Page 10[90457:4863973] [10] takes 53
2015-11-09 21:16:05.033 Untitled Page 10[90457:4863925] [14] takes 54
2015-11-09 21:16:05.037 Untitled Page 10[90457:4863925] [14] takes 55
2015-11-09 21:16:05.060 Untitled Page 10[90457:4863925] [14] takes 56
2015-11-09 21:16:05.065 Untitled Page 10[90457:4863925] [14] takes 57
2015-11-09 21:16:05.072 Untitled Page 10[90457:4863925] [14] takes 58
2015-11-09 21:16:05.082 Untitled Page 10[90457:4863981] [19] takes 59
2015-11-09 21:16:05.084 Untitled Page 10[90457:4863916] [2] takes 60
2015-11-09 21:16:05.093 Untitled Page 10[90457:4863980] [18] takes 61
2015-11-09 21:16:05.100 Untitled Page 10[90457:4863968] [5] takes 62
2015-11-09 21:16:05.107 Untitled Page 10[90457:4863966] [3] takes 63
2015-11-09 21:16:05.111 Untitled Page 10[90457:4863966] [3] takes 64
2015-11-09 21:16:05.119 Untitled Page 10[90457:4863966] [3] takes 65
2015-11-09 21:16:05.124 Untitled Page 10[90457:4863966] [3] takes 66
2015-11-09 21:16:05.129 Untitled Page 10[90457:4863967] [4] takes 67
2015-11-09 21:16:05.135 Untitled Page 10[90457:4863967] [4] takes 68
2015-11-09 21:16:05.139 Untitled Page 10[90457:4863974] [11] takes 69
2015-11-09 21:16:05.144 Untitled Page 10[90457:4863975] [12] takes 70
2015-11-09 21:16:05.152 Untitled Page 10[90457:4863915] [1] takes 71
2015-11-09 21:16:05.156 Untitled Page 10[90457:4863976] [13] takes 72
2015-11-09 21:16:05.160 Untitled Page 10[90457:4863976] [13] takes 73
2015-11-09 21:16:05.211 Untitled Page 10[90457:4863976] [13] takes 74
2015-11-09 21:16:05.220 Untitled Page 10[90457:4863976] [13] takes 75
2015-11-09 21:16:05.224 Untitled Page 10[90457:4863976] [13] takes 76
2015-11-09 21:16:05.235 Untitled Page 10[90457:4863976] [13] takes 77
2015-11-09 21:16:05.237 Untitled Page 10[90457:4863925] [14] takes 78
2015-11-09 21:16:05.243 Untitled Page 10[90457:4863981] [19] takes 79
2015-11-09 21:16:05.250 Untitled Page 10[90457:4863981] [19] takes 80
2015-11-09 21:16:05.255 Untitled Page 10[90457:4863981] [19] takes 81
2015-11-09 21:16:05.261 Untitled Page 10[90457:4863981] [19] takes 82
2015-11-09 21:16:05.268 Untitled Page 10[90457:4863981] [19] takes 83
2015-11-09 21:16:05.273 Untitled Page 10[90457:4863981] [19] takes 84
2015-11-09 21:16:05.278 Untitled Page 10[90457:4863981] [19] takes 85
2015-11-09 21:16:05.284 Untitled Page 10[90457:4863981] [19] takes 86
2015-11-09 21:16:05.291 Untitled Page 10[90457:4863981] [19] takes 87
2015-11-09 21:16:05.296 Untitled Page 10[90457:4863981] [19] takes 88
2015-11-09 21:16:05.299 Untitled Page 10[90457:4863974] [11] takes 89
2015-11-09 21:16:05.305 Untitled Page 10[90457:4863974] [11] takes 90
2015-11-09 21:16:05.310 Untitled Page 10[90457:4863974] [11] takes 91
2015-11-09 21:16:05.317 Untitled Page 10[90457:4863974] [11] takes 92
2015-11-09 21:16:05.322 Untitled Page 10[90457:4863978] [17] takes 93
2015-11-09 21:16:05.327 Untitled Page 10[90457:4863978] [17] takes 94
2015-11-09 21:16:05.333 Untitled Page 10[90457:4863978] [17] takes 95
2015-11-09 21:16:05.338 Untitled Page 10[90457:4863978] [17] takes 96
2015-11-09 21:16:05.343 Untitled Page 10[90457:4863978] [17] takes 97
2015-11-09 21:16:05.348 Untitled Page 10[90457:4863978] [17] takes 98
2015-11-09 21:16:05.353 Untitled Page 10[90457:4863978] [17] takes 99
user3441734
  • 16,722
  • 2
  • 40
  • 59
  • I'm not sure what you mean by your last sentence. Can you elaborate? – Nicolas B. Nov 09 '15 at 19:53
  • you dispatch the consumers in specific order. there is no guaranty about execution order. it has nothing with the log! one operation block can run in chunks, not continuously. you dispatch first the consumer1 and than the consumer2. in more complex scenario can first do the job consumer2. – user3441734 Nov 09 '15 at 20:09