ssync receiver get an odd SSYNC command and raise a exception

[Charles Hsu]

I got a exception form ssync receiver

$ cat /var/log/swift/all.log|grep "need more than 1 value to unpack"
Jun 25 07:26:29 localhost.localdomain object-server: 192.168.12.13/d41/1791 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 07:43:12 localhost.localdomain object-server: 192.168.12.14/d42/2810 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 07:56:21 localhost.localdomain object-server: 192.168.12.14/d42/1850 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 07:56:23 localhost.localdomain object-server: 192.168.12.14/d41/1936 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 07:58:48 localhost.localdomain object-server: 192.168.12.13/d43/3089 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 08:06:31 localhost.localdomain object-server: 192.168.12.14/d42/3377 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 08:06:31 localhost.localdomain object-server: 192.168.12.14/d43/3786 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 08:14:45 localhost.localdomain object-server: 192.168.12.12/d41/1659 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 08:14:45 localhost.localdomain object-server: 192.168.12.12/d43/1311 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 08:17:21 localhost.localdomain object-server: 192.168.12.13/d40/168 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 08:29:18 localhost.localdomain object-server: 192.168.12.14/d41/2602 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 322, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack
Jun 25 08:57:46 localhost.localdomain object-server: 192.168.12.11/d42/2670 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 323, in updates#012 subreq = swob.Request.blank(#012ValueError: need more than 1 value to unpack
Jun 25 08:57:46 localhost.localdomain object-server: 192.168.12.11/d41/2925 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 105, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 323, in updates#012 subreq = swob.Request.blank(#012ValueError: need more than 1 value to unpack

 and I add few debug msg in obj/ssync_receiver.py (updates()).

        while True:
            with exceptions.MessageTimeout(
                    self.app.client_timeout, 'updates line'):
                line = self.fp.readline(self.app.network_chunk_size)
                self.app.logger.debug('## Receiver: 2[%s]' % line)
            if not line or line.strip() == ':UPDATES: END':
                break
            # Read first line METHOD PATH of subrequest.
            method, path = line.strip().split(' ', 1)
            subreq = swob.Request.blank(

Add receiver got an odd command "#003#000#000#000#020#001#000#000#000#000#000#000]#006#000#000#000#000#000#000#001#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#004#000#015#002#000?^#014#013#012]".

Jun 25 09:17:37 localhost.localdomain object-server: ## Receiver: 2[PUT /AUTH_test/ssbench-ectest-miniscule-writeonly-50fullness_0517_225336_60_000061_ec64-isolation/objects_002289#015#012]
Jun 25 09:17:37 localhost.localdomain object-server: ## Receiver: 2[PUT /AUTH_test/ssbench-ectest-small-writeonly-50fullness_0517_225336_82_000012_ec64-isolation/objects_000613#015#012]
Jun 25 09:17:37 localhost.localdomain object-server: ## Receiver: 2[PUT /AUTH_test/ssbench-ectest-miniscule-writeonly-50fullness_0517_225336_59_000077_ec64-isolation/objects_002875#015#012]
Jun 25 09:17:37 localhost.localdomain object-server: ## Receiver: 2[PUT /AUTH_test/ssbench-ectest-miniscule-writeonly_000081_ec64-isolation/objects_019542#015#012]
Jun 25 09:17:37 localhost.localdomain object-server: ## Receiver: 2[PUT /AUTH_test/ssbench-ectest-miniscule-writeonly-0510_222319_000063_ec64-isolation/objects_003040#015#012]
Jun 25 09:17:37 localhost.localdomain object-server: ## Receiver: 2[PUT /AUTH_test/ssbench-ectest-small-writeonly-50fullness_0517_225336_72_000004_ec64-isolation/objects_001477#015#012]
Jun 25 09:17:38 localhost.localdomain object-server: ## Receiver: 2[PUT /AUTH_test/ssbench-ectest-large-writeonly-50fullness_0517_225336_86_000011_ec64-isolation/objects_000046#015#012]
Jun 25 09:17:41 localhost.localdomain object-server: ## Receiver: 2[#003#000#000#000#020#001#000#000#000#000#000#000]#006#000#000#000#000#000#000#001#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#000#004#000#015#002#000?^#014#013#012]
Jun 25 09:17:41 localhost.localdomain object-server: 192.168.12.14/d43/1069 EXCEPTION in replication.Receiver: #012Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 106, in __call__#012 for data in self.updates():#012 File "/usr/lib/pymodules/python2.7/swift/obj/ssync_receiver.py", line 327, in updates#012 method, path = line.strip().split(' ', 1)#012ValueError: need more than 1 value to unpack

[clayg (clay-gerrard)]

Can you find the data files on disk and which node was sending to this receiver. Which part.

Is it just some N parts that fail everytime or does the problem seem to move around randomly?

Is thing comes from a handoff or a partner primary.

[clayg (clay-gerrard)]

Also, the loggers translation of the string control chacaters is sorta hard to reason about - can you try to format the line with a repr:

    diff --git a/swift/obj/ssync_receiver.py b/swift/obj/ssync_receiver.py
    index 6aeb4c4..3c5a82b 100644
    --- a/swift/obj/ssync_receiver.py
    +++ b/swift/obj/ssync_receiver.py
    @@ -296,6 +296,7 @@ class Receiver(object):
                 with exceptions.MessageTimeout(
                         self.app.client_timeout, 'updates line'):
                     line = self.fp.readline(self.app.network_chunk_size)
    + self.app.logger.debug('## Receiver: %r' % line)
                 if not line or line.strip() == ':UPDATES: END':
                     break
                 # Read first line METHOD PATH of subrequest.

[Charles Hsu (charles0126)]

I'm confused that. I'll apply your code and increase concurrency of reconstructor and see what I can get.

[paul luse (paul-e-luse)]

Hi Charles, any update on this?

[Charles Hsu (charles0126)]

I think this bug might fixed from another patch, I haven't see that a while.
Looks I need to test it against latest swift.

[Launchpad Janitor (janitor)]

[Expired for OpenStack Object Storage (swift) because there has been no activity for 60 days.]