error with LIST: protocol error, got '{' as reply type byte

[clu3]

Hi Nicolas,
I am trying to implement a Message Queue (job queue) using the master branch phpredis with latest redis, and working with LIST

Suppose my queue name is "queue:high". During the process of pushing and popping my test item (which is a json_encoded string) sometimes I get this RedisException

protocol error, got '{' as reply type byte

I unfortunately cannot find out exactly when this happen but my guess is it has to do with the 2 processes trying to pop one item from the list. That's actually the only thing I could think of

(My main worker loops indefinitely to pop items from the queue)

Please let me know if I need to provide anything else. Thank you Nicolas

[nicolasff]

Hi Steve,

'{' looks like the first character of some data, not really what one would expect to see in the Redis protocol. Do you know more about the conditions in which this happens? I will try running tests in parallel but if you have some code to reproduce the issue that would be perfect.

Thanks.

[clu3]

Hi Nicolas,

The "{" is part of json_encode string, and it works elsewhere normally. Please note, the bug I reported earlier ONLY happens when I have called pcntl_fork().

Below is the two files I've just made to make it simple: daemon.php is the worker that loops infinitely to pop job and perform. gen_job.php can be run as "gen_job.php 3" to push 3 jobs to the queue named "queue".

Gist: https://gist.github.com/1241970

HOW TO RUN

• On terminal 1, run "php daemon.php" and watch it printing out time stamps and any job it's found
  (At start of each loop (interval of 1 second), I print out "start loop" with a time stamp)
• On terminal 2, if you want to push 2 jobs, run "php gen_job.php 2"

BUGS
Unfortunately with those 2 files I cannot reproduce the errors stated, but I found 2 "weird" things, so I'll post them here for convenience

1. After pushing/processing 2 jobs, the daemon worker keeps successfully popping a job with strange values, like ":38", ":39", as belows

steve@clu3:~/Code/git/xxx/public$ php daemon.php
start loop @ 16:59:12
start loop @ 16:59:13
start loop @ 16:59:14
start loop @ 16:59:15
got job @ 16:59:15
string(63) "{"class":"foo","method":"bar","params":[1,2,4],"ts":"16:59:14"}"

start loop @ 16:59:15
start loop @ 16:59:16
start loop @ 16:59:17
start loop @ 16:59:18
start loop @ 16:59:19
start loop @ 16:59:20
got job @ 16:59:20
string(63) "{"class":"foo","method":"bar","params":[1,2,4],"ts":"16:59:14"}"

start loop @ 16:59:20
start loop @ 16:59:21
start loop @ 16:59:22
start loop @ 16:59:23
got job @ 16:59:23
string(3) ":38"

start loop @ 16:59:23
start loop @ 16:59:24
start loop @ 16:59:25
start loop @ 16:59:26
start loop @ 16:59:27
start loop @ 16:59:28
start loop @ 16:59:29
start loop @ 16:59:30
got job @ 16:59:30
string(3) ":39"

--- END of LOG---

1. The delayed time between 2 successive jobs should have been less than 1 loop interval (1 second in this case), yet in the above example, even though 2 jobs were pushed at the same time, they were popped out at quite distant times, one at 16:59:15, and one at 16:59:23

NOTE:
If I changed $fork = true in daemon.php, that is ,I run things sequentially, everything works as expected

So I'm not sure what exact problems fork() is causing here

Thanks Nicolas

[nicolasff]

Ah, very interesting. I guess that after fork(), the two PHP processes keep using the same socket, which is shared. You are seeing a race condition between two processes trying to read from the same socket.

You should reconnect to Redis after the fork(), I expect this will fix your issue.

[clu3]

Thanks Nicolas,
If I reset the redis connection it works perfectly!!

However, I still don't understand why there should be a race condition since only the parent is accessing the queue. Even if the redis connection is available to the child, the child is not using it (child only performs the job), so it shouldn't affect the parent reading the socket.

I think there's still something weird here