Application versions (embedded in logfile):
          Nevow: 0.10.0
        Twisted: 10.1.0
allmydata-tahoe: 1.9.1
       foolscap: 0.6.3
           mock: 0.8.0rc2
       platform: Windows-7-6.1.7601-SP1
      pyOpenSSL: 0.12
         pyasn1: unknown
       pycrypto: 2.4
     pycryptopp: 0.5.29
         python: 2.6.6
     setuptools: 0.6c16dev3
     simplejson: 2.3.2
        sqlite3: 2.4.1
        twisted: 10.1.0
           zfec: 1.4.7-r362
 zope.interface: unknown
PID: 3912

local#0 06:23:13.255: Node constructed. allmydata-tahoe: 1.9.1,
foolscap: 0.6.3,
pycryptopp: 0.5.29,
zfec: 1.4.7-r362,
Twisted: 10.1.0,
Nevow: 0.10.0,
zope.interface: unknown,
python: 2.6.6,
platform: Windows-7-6.1.7601-SP1,
pyOpenSSL: 0.12,
simplejson: 2.3.2,
pycrypto: 2.4,
pyasn1: unknown,
mock: 0.8.0rc2,
sqlite3: 2.4.1 [sqlite 3.5.9],
setuptools: 0.6c16dev3

local#1 06:23:13.256: StorageServer created
local#2 06:23:13.289: want to subscribe, but no introducer yet
local#3 06:23:13.289: init_web(webport=tcp:3456:interface=127.0.0.1)
local#4 06:23:13.371: Loaded.
local#5 06:23:13.371: Log opened.
local#6 06:23:13.371: twistd 10.1.0 (C:\Python26\python.exe 2.6.6) starting up.
local#7 06:23:13.371: reactor class: twisted.internet.selectreactor.SelectReactor.
local#8 06:23:13.372: foolscap.pb.Listener starting on 55392
local#9 06:23:13.372: Starting factory <Listener at 0x48cd5c8 on 55392 with tubs aty4re3a3ygvb6a2gext5vbcgdzs4ihk>
local#10 06:23:13.372: nevow.appserver.NevowSite starting on 3456
local#11 06:23:13.372: Starting factory <nevow.appserver.NevowSite instance at 0x0000000002708408>
local#12 06:23:13.372: Node.startService
local#13 06:23:13.372: My pid: 3912
local#14 06:23:13.374: Node._startService
local#15 06:23:13.374: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to hpd3hn75ggwujdsacpd47r4yj6tahutj
local#16 06:23:13.374: connectTCP to ('rosenkeller.org', 32121)
local#17 06:23:13.374: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to hpd3hn75] at 0x0000000002706B70>
local#18 06:23:13.375: twisted.internet.protocol.DatagramProtocol starting on 57066
local#19 06:23:13.375: Starting protocol <twisted.internet.protocol.DatagramProtocol instance at 0x000000000270B488>
local#20 06:23:13.385: (Port 57066 Closed)
local#21 06:23:13.385: Stopping protocol <twisted.internet.protocol.DatagramProtocol instance at 0x000000000270B488>
local#22 06:23:13.448: Negotiation started
local#26 06:23:13.490: Tub location set to 78.83.249.174
local#27 06:23:13.490: client running
local#28 06:23:13.490: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to sqlcmsbk34qui3vpstyokohufzffwkt2
local#29 06:23:13.490: connectTCP to ('184.106.205.58', 46598)
local#30 06:23:13.490: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to sqlcmsbk] at 0x000000000270EA20>
local#31 06:23:13.492: want to publish, but no introducer yet
local#32 06:23:13.494: want to publish, but no introducer yet
local#33 06:23:13.494: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to duszrv4xk7yinbyjrbxiirvepoik7jhm
local#34 06:23:13.494: connectTCP to ('rosenkeller.org', 42247)
local#35 06:23:13.494: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to duszrv4x] at 0x000000000270EE10>
local#41 06:23:14.540: Negotiation started
local#45 06:23:14.540: Negotiation started
local#67 06:23:14.957: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '5f276dfe842c13f4 5'}
local#70 06:23:14.957: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to hpd3hn75] at 0x0000000002706B70> won
local#71 06:23:14.957: connectorFinished (<foolscap.negotiate.TubConnector object at 0x0000000002706B38 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to hpd3hn75ggwujdsacpd47r4yj6tahutj>)
local#74 06:23:15.012: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'cf3b9daa4b1db809 1'}
local#77 06:23:15.012: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to duszrv4x] at 0x000000000270EE10> won
local#78 06:23:15.012: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000270EDA0 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to duszrv4xk7yinbyjrbxiirvepoik7jhm>)
local#79 06:23:15.013: <Uploader #1>: got helper connection, getting versions
local#85 06:23:15.417: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'ecd6175f02242f10 6'}
local#88 06:23:15.417: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to sqlcmsbk] at 0x000000000270EA20> won
local#89 06:23:15.417: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000270E6D8 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to sqlcmsbk34qui3vpstyokohufzffwkt2>)
local#90 06:23:15.559: connected to introducer, getting versions
local#91 06:23:15.703: got introducer version: {'http://allmydata.org/tahoe/protocols/introducer/v1': {}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#92 06:23:15.861: received 14 announcements
local#93 06:23:15.861: announcement for [storage]: ('pb://huadamis74e2mwtgiq23a2jm5l7m72hi@server.palatinus.cz:9001/td6smgu5oavsihyddp5pyul2gutjk4al', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'slush@centrum.cz-future', 'allmydata-tahoe/1.8.3', '1.0.0')
local#94 06:23:15.862: announcement for [storage]: ('pb://b55ww7wazcrwu4owhlxpmvx6qvr4p3iy@bach-home.ath.cx:6001,127.0.0.1:6001/zgqskear5ddhhy45zflqrpxwdgaf2ivv', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'pascal.bach@gmx.ch-Horus', 'allmydata-tahoe/1.9.1', '1.0.0')
local#95 06:23:15.862: announcement for [storage]: ('pb://aty4re3a3ygvb6a2gext5vbcgdzs4ihk@78.83.249.174/pcdvfeyl54xucaynoytisncf7wrqxknw', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'ianchov@gmail.com', 'allmydata-tahoe/1.9.1', '1.0.0')
local#96 06:23:15.862: announcement for [storage]: ('pb://jbrse33y3gmtpauhhgfsrti4o4mzlcsk@68.233.149.2:8766,127.0.0.1:8766/5uicwx4grz4kufuuy5x4fzckd4pdmpt2', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'jharris@harrisdev.com-Cat', 'allmydata-tahoe/1.8.2', '1.0.0')
local#97 06:23:15.862: announcement for [storage]: ('pb://pmitrhwg7hminstxvijbyzefsovwq7hf@gratch.willden.org:45625/tlh2ptoep3inaxbfminldcq4cbdj72xq', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'shawn@willden.org-gratch', 'allmydata-tahoe/1.9.1', '1.0.0')
local#98 06:23:15.862: announcement for [storage]: ('pb://inxoy6uiulkr2uwm6s3rmz6jzyiywkvi@cerezal.selfip.net:8098/aqkqublpeblnfnp7phnies7oght36l7o', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'cerezal@gmx.net-cerezal', 'allmydata-tahoe/1.9.1', '1.0.0')
local#99 06:23:15.862: announcement for [storage]: ('pb://gbytbnxw2hkbpjslf7mevzejefmdomtb@rhp997.dyndns.org:33386/f6mmdhhwjhsz7inwewfzpy6ptjat5mc6', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'steve.dodson@gmail.com-hiro', 'allmydata-tahoe/1.7.1', '1.0.0')
local#100 06:23:15.862: announcement for [storage]: ('pb://baeq4skxppta2cc6wnjfv7k2uu7ms4b6@sln.superlumin.com:33892/2oo5qrfqqg6ejbuioyfmx2fadq56lb4c', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'bradrupp@gmail.com-sln', 'allmydata-tahoe/1.8.3', '1.0.0')
local#101 06:23:15.862: announcement for [storage]: ('pb://kvj2xrmmti3wp2albm3mmo3ulead5fy2@kruemi.homelinux.org:8098,192.168.10.10:8098,10.248.5.3:8098,127.0.0.1:8098/ma6dc7ebq3xt7t6wsbionskb57ioldkh', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'marco.tedaldi@gmail.com', 'allmydata-tahoe/1.8.3', '1.0.0')
local#102 06:23:15.862: announcement for [storage]: ('pb://hpd3hn75ggwujdsacpd47r4yj6tahutj@rosenkeller.org:32121/j2zqmgd7bg7rd6icryxn2g4ym4bncoam', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'christoph@rosenkeller.org-bender', 'allmydata-tahoe/1.8.3', '1.0.0')
local#103 06:23:15.864: announcement for [storage]: ('pb://vifimgiwol6shdmyoxyqvet5oz6dqnt5@earney.homedns.org:49244/6qa3vi342juxqkgxorauxdpaqxe47jwa', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'billy.earney@gmail.com', 'allmydata-tahoe/1.8.3', '1.0.0')
local#104 06:23:15.864: announcement for [storage]: ('pb://g4xvpwqadyiwfu26qfxkgmjjxmony52p@63.233.155.10:33386/3yshj7nceglj7dvejy6qnwtmidmdkuxs', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'steve.dodson@gmail.com-rhp997', 'allmydata-tahoe/1.8.3', '1.0.0')
local#105 06:23:15.864: announcement for [storage]: ('pb://qivwuhf6cnon45sld7lq5a3iugsjjqmw@if3-1.no-ip.org:33892/6tekcmlfjtwr7634e4blpe3acecjp7ei', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'bradrupp@gmail.com-if3-1', 'allmydata-tahoe/1.8.3', '1.0.0')
local#106 06:23:15.864: announcement for [storage]: ('pb://kqyu52yzkipbt5ktyu6x56s6isi2khyc@foo.asia-king.co.uk:3917/h66p63tgqkfodqxpos3pt2emjziov6bp', 'storage', 'RIStorageServer.tahoe.allmydata.com', 'sabotrax@gmail.com', 'allmydata-tahoe/1.9.1', '1.0.0')
local#107 06:23:15.865: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to huadamis74e2mwtgiq23a2jm5l7m72hi
local#108 06:23:15.865: connectTCP to ('server.palatinus.cz', 9001)
local#109 06:23:15.865: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to huadamis] at 0x000000000271F080>
local#110 06:23:15.865: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to b55ww7wazcrwu4owhlxpmvx6qvr4p3iy
local#111 06:23:15.865: connectTCP to ('127.0.0.1', 6001)
local#112 06:23:15.865: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to b55ww7wa] at 0x000000000271F2B0>
local#113 06:23:15.865: connectTCP to ('bach-home.ath.cx', 6001)
local#114 06:23:15.865: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to b55ww7wa] at 0x000000000271F358>
local#115 06:23:15.865: Negotiation started
local#116 06:23:15.865: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to jbrse33y3gmtpauhhgfsrti4o4mzlcsk
local#117 06:23:15.865: connectTCP to ('127.0.0.1', 8766)
local#118 06:23:15.865: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to jbrse33y] at 0x0000000002723198>
local#119 06:23:15.865: connectTCP to ('68.233.149.2', 8766)
local#120 06:23:15.865: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to jbrse33y] at 0x0000000002723240>
local#121 06:23:15.865: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to pmitrhwg7hminstxvijbyzefsovwq7hf
local#122 06:23:15.865: connectTCP to ('gratch.willden.org', 45625)
local#123 06:23:15.865: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to pmitrhwg] at 0x0000000002723400>
local#124 06:23:15.867: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to inxoy6uiulkr2uwm6s3rmz6jzyiywkvi
local#125 06:23:15.867: connectTCP to ('cerezal.selfip.net', 8098)
local#126 06:23:15.867: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to inxoy6ui] at 0x00000000027235F8>
local#127 06:23:15.867: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to gbytbnxw2hkbpjslf7mevzejefmdomtb
local#128 06:23:15.867: connectTCP to ('rhp997.dyndns.org', 33386)
local#129 06:23:15.867: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to gbytbnxw] at 0x00000000027237F0>
local#130 06:23:15.867: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to baeq4skxppta2cc6wnjfv7k2uu7ms4b6
local#131 06:23:15.867: connectTCP to ('sln.superlumin.com', 33892)
local#132 06:23:15.867: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to baeq4skx] at 0x00000000027239E8>
local#133 06:23:15.867: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to kvj2xrmmti3wp2albm3mmo3ulead5fy2
local#134 06:23:15.867: connectTCP to ('127.0.0.1', 8098)
local#135 06:23:15.867: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723B38>
local#136 06:23:15.868: connectTCP to ('10.248.5.3', 8098)
local#137 06:23:15.868: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723DA0>
local#138 06:23:15.868: connectTCP to ('192.168.10.10', 8098)
local#139 06:23:15.868: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723EB8>
local#140 06:23:15.868: connectTCP to ('kruemi.homelinux.org', 8098)
local#141 06:23:15.868: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723FD0>
local#142 06:23:15.868: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to vifimgiwol6shdmyoxyqvet5oz6dqnt5
local#143 06:23:15.868: connectTCP to ('earney.homedns.org', 49244)
local#144 06:23:15.868: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to vifimgiw] at 0x000000000272A2E8>
local#145 06:23:15.868: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to g4xvpwqadyiwfu26qfxkgmjjxmony52p
local#146 06:23:15.868: connectTCP to ('63.233.155.10', 33386)
local#147 06:23:15.868: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to g4xvpwqa] at 0x000000000272A470>
local#148 06:23:15.868: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to qivwuhf6cnon45sld7lq5a3iugsjjqmw
local#149 06:23:15.868: connectTCP to ('if3-1.no-ip.org', 33892)
local#150 06:23:15.868: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to qivwuhf6] at 0x000000000272A6D8>
local#151 06:23:15.868: TubConnector created from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to kqyu52yzkipbt5ktyu6x56s6isi2khyc
local#152 06:23:15.868: connectTCP to ('foo.asia-king.co.uk', 3917)
local#153 06:23:15.868: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kqyu52yz] at 0x000000000272A8D0>
local#154 06:23:15.874: got connection to aty4re3a, getting versions
local#155 06:23:15.877: aty4re3a provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 325612279296L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.9.1'}
local#156 06:23:15.924: got connection to hpd3hn75, getting versions
local#157 06:23:15.964: Negotiation started
local#161 06:23:15.986: hpd3hn75 provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 1309676035072L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#167 06:23:16.059: Negotiation started
local#171 06:23:16.078: Negotiation started
local#180 06:23:16.138: Negotiation started
local#187 06:23:16.323: Negotiation started
local#194 06:23:16.345: Negotiation started
local#198 06:23:16.391: Negotiation started
local#209 06:23:16.515: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '9c7e819cf82f4771 31'}
local#212 06:23:16.516: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to huadamis] at 0x000000000271F080> won
local#213 06:23:16.516: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000271F0B8 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to huadamis74e2mwtgiq23a2jm5l7m72hi>)
local#229 06:23:16.591: got connection to huadamis, getting versions
local#232 06:23:16.592: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '5c7b22442c131707 3'}
local#235 06:23:16.592: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to b55ww7wa] at 0x000000000271F358> won
local#236 06:23:16.592: told to disconnect
local#237 06:23:16.592: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000271F1D0 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to b55ww7wazcrwu4owhlxpmvx6qvr4p3iy>)
local#238 06:23:16.592: Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to b55ww7wa] at 0x000000000271F2B0>
local#239 06:23:16.592: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000271F1D0 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to b55ww7wazcrwu4owhlxpmvx6qvr4p3iy>)
local#240 06:23:16.667: got connection to b55ww7wa, getting versions
local#241 06:23:16.677: huadamis provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 1024776559616L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#242 06:23:16.736: b55ww7wa provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 787091998720L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.9.1'}
local#243 06:23:16.831: Negotiation started
local#247 06:23:16.869: Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to jbrse33y] at 0x0000000002723198>
local#248 06:23:16.888: Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723B38>
local#249 06:23:16.897: Negotiation started
local#253 06:23:16.954: Negotiation started
local#259 06:23:16.971: startENCRYPTED(isClient=True, encrypted=True)
local#260 06:23:16.971: startTLS, client=True
local#261 06:23:16.971: Negotiate.sendHello (isClient=True): {'my-incarnation': '9a6c03436c11e75e', 'last-connection': 'none 0', 'my-tub-id': 'aty4re3a3ygvb6a2gext5vbcgdzs4ihk', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#262 06:23:17.007: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: f61601be67f0278b\r\nmy-tub-id: inxoy6uiulkr2uwm6s3rmz6jzyiywkvi\r\n\r\n'
local#263 06:23:17.007: evaluateHello(isClient=True): offer={'my-tub-id': 'inxoy6uiulkr2uwm6s3rmz6jzyiywkvi', 'my-incarnation': 'f61601be67f0278b', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#264 06:23:17.007: iAmTheMaster: False
local#265 06:23:17.019: dataReceived(isClient=True,phase=0,options={}): 'HTTP/1.1 101 Switching Protocols\r\nUpgrade: TLS/1.0, PB/1.0\r\nConnection: Upgrade\r\n\r\n'
local#266 06:23:17.020: handlePLAINTEXTClient: header='HTTP/1.1 101 Switching Protocols
Upgrade: TLS/1.0, PB/1.0
Connection: Upgrade'
local#267 06:23:17.020: startENCRYPTED(isClient=True, encrypted=True)
local#268 06:23:17.020: startTLS, client=True
local#269 06:23:17.020: Negotiate.sendHello (isClient=True): {'my-incarnation': '9a6c03436c11e75e', 'last-connection': 'none 0', 'my-tub-id': 'aty4re3a3ygvb6a2gext5vbcgdzs4ihk', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#270 06:23:17.085: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: e02e66597cd725d7\r\nmy-tub-id: pmitrhwg7hminstxvijbyzefsovwq7hf\r\n\r\n'
local#271 06:23:17.085: evaluateHello(isClient=True): offer={'my-tub-id': 'pmitrhwg7hminstxvijbyzefsovwq7hf', 'my-incarnation': 'e02e66597cd725d7', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#272 06:23:17.085: iAmTheMaster: False
local#273 06:23:17.135: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: 7807f4a8f5d836a4\r\nmy-tub-id: baeq4skxppta2cc6wnjfv7k2uu7ms4b6\r\n\r\n'
local#274 06:23:17.135: evaluateHello(isClient=True): offer={'my-tub-id': 'baeq4skxppta2cc6wnjfv7k2uu7ms4b6', 'my-incarnation': '7807f4a8f5d836a4', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#275 06:23:17.135: iAmTheMaster: False
local#276 06:23:17.148: dataReceived(isClient=True,phase=0,options={}): 'HTTP/1.1 101 Switching Protocols\r\nUpgrade: TLS/1.0, PB/1.0\r\nConnection: Upgrade\r\n\r\n'
local#277 06:23:17.148: handlePLAINTEXTClient: header='HTTP/1.1 101 Switching Protocols
Upgrade: TLS/1.0, PB/1.0
Connection: Upgrade'
local#278 06:23:17.148: startENCRYPTED(isClient=True, encrypted=True)
local#279 06:23:17.148: startTLS, client=True
local#280 06:23:17.148: Negotiate.sendHello (isClient=True): {'my-incarnation': '9a6c03436c11e75e', 'last-connection': 'none 0', 'my-tub-id': 'aty4re3a3ygvb6a2gext5vbcgdzs4ihk', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#281 06:23:17.180: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: 03a292f2a643574e\r\nmy-tub-id: kvj2xrmmti3wp2albm3mmo3ulead5fy2\r\n\r\n'
local#282 06:23:17.181: evaluateHello(isClient=True): offer={'my-tub-id': 'kvj2xrmmti3wp2albm3mmo3ulead5fy2', 'my-incarnation': '03a292f2a643574e', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#283 06:23:17.181: iAmTheMaster: False
local#284 06:23:17.181: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: 93a15c061ffd0b07\r\nmy-tub-id: g4xvpwqadyiwfu26qfxkgmjjxmony52p\r\n\r\n'
local#285 06:23:17.181: evaluateHello(isClient=True): offer={'my-tub-id': 'g4xvpwqadyiwfu26qfxkgmjjxmony52p', 'my-incarnation': '93a15c061ffd0b07', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#286 06:23:17.183: iAmTheMaster: False
local#287 06:23:17.206: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: 8703d6eb24bbf81a\r\nmy-tub-id: kqyu52yzkipbt5ktyu6x56s6isi2khyc\r\n\r\n'
local#288 06:23:17.206: evaluateHello(isClient=True): offer={'my-tub-id': 'kqyu52yzkipbt5ktyu6x56s6isi2khyc', 'my-incarnation': '8703d6eb24bbf81a', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#289 06:23:17.206: iAmTheMaster: False
local#290 06:23:17.303: dataReceived(isClient=True,phase=0,options={}): 'HTTP/1.1 101 Switching Protocols\r\nUpgrade: TLS/1.0, PB/1.0\r\nConnection: Upgrade\r\n\r\n'
local#291 06:23:17.303: handlePLAINTEXTClient: header='HTTP/1.1 101 Switching Protocols
Upgrade: TLS/1.0, PB/1.0
Connection: Upgrade'
local#292 06:23:17.303: startENCRYPTED(isClient=True, encrypted=True)
local#293 06:23:17.303: startTLS, client=True
local#294 06:23:17.305: Negotiate.sendHello (isClient=True): {'my-incarnation': '9a6c03436c11e75e', 'last-connection': 'none 0', 'my-tub-id': 'aty4re3a3ygvb6a2gext5vbcgdzs4ihk', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#295 06:23:17.305: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: f61601be67f0278b 7\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#296 06:23:17.305: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: f61601be67f0278b 7
initial-vocab-table-index: 1 bb33
local#297 06:23:17.305: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'f61601be67f0278b 7'}
local#298 06:23:17.305: Negotiate.switchToBanana(isClient=True)
local#299 06:23:17.305: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#300 06:23:17.305: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to inxoy6ui] at 0x00000000027235F8> won
local#301 06:23:17.305: connectorFinished (<foolscap.negotiate.TubConnector object at 0x0000000002723588 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to inxoy6uiulkr2uwm6s3rmz6jzyiywkvi>)
local#302 06:23:17.443: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: 03a292f2a643574e 2\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#303 06:23:17.443: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: 03a292f2a643574e 2
initial-vocab-table-index: 1 bb33
local#304 06:23:17.443: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '03a292f2a643574e 2'}
local#305 06:23:17.443: Negotiate.switchToBanana(isClient=True)
local#306 06:23:17.443: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#307 06:23:17.444: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723FD0> won
local#308 06:23:17.444: told to disconnect
local#309 06:23:17.444: Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723DA0>
local#310 06:23:17.444: told to disconnect
local#311 06:23:17.444: connectorFinished (<foolscap.negotiate.TubConnector object at 0x0000000002723BA8 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to kvj2xrmmti3wp2albm3mmo3ulead5fy2>)
local#312 06:23:17.444: Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kvj2xrmm] at 0x0000000002723EB8>
local#313 06:23:17.444: connectorFinished (<foolscap.negotiate.TubConnector object at 0x0000000002723BA8 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to kvj2xrmmti3wp2albm3mmo3ulead5fy2>)
local#314 06:23:17.448: got connection to inxoy6ui, getting versions
local#315 06:23:17.463: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: 8703d6eb24bbf81a 5\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#316 06:23:17.463: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: 8703d6eb24bbf81a 5
initial-vocab-table-index: 1 bb33
local#317 06:23:17.463: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '8703d6eb24bbf81a 5'}
local#318 06:23:17.463: Negotiate.switchToBanana(isClient=True)
local#319 06:23:17.463: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#320 06:23:17.463: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to kqyu52yz] at 0x000000000272A8D0> won
local#321 06:23:17.463: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000272A860 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to kqyu52yzkipbt5ktyu6x56s6isi2khyc>)
local#322 06:23:17.509: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: e02e66597cd725d7 4\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#323 06:23:17.509: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: e02e66597cd725d7 4
initial-vocab-table-index: 1 bb33
local#324 06:23:17.509: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'e02e66597cd725d7 4'}
local#325 06:23:17.509: Negotiate.switchToBanana(isClient=True)
local#326 06:23:17.509: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#327 06:23:17.509: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to pmitrhwg] at 0x0000000002723400> won
local#328 06:23:17.509: connectorFinished (<foolscap.negotiate.TubConnector object at 0x0000000002723390 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to pmitrhwg7hminstxvijbyzefsovwq7hf>)
local#329 06:23:17.517: got connection to kvj2xrmm, getting versions
local#330 06:23:17.528: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: 7807f4a8f5d836a4 3\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#331 06:23:17.528: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: 7807f4a8f5d836a4 3
initial-vocab-table-index: 1 bb33
local#332 06:23:17.528: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '7807f4a8f5d836a4 3'}
local#333 06:23:17.528: Negotiate.switchToBanana(isClient=True)
local#334 06:23:17.528: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#335 06:23:17.528: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to baeq4skx] at 0x00000000027239E8> won
local#336 06:23:17.528: connectorFinished (<foolscap.negotiate.TubConnector object at 0x0000000002723978 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to baeq4skxppta2cc6wnjfv7k2uu7ms4b6>)
local#337 06:23:17.529: got connection to kqyu52yz, getting versions
local#338 06:23:17.532: Negotiation started
local#339 06:23:17.532: initClient: to target pb://qivwuhf6cnon45sld7lq5a3iugsjjqmw
local#340 06:23:17.532: sendPlaintextClient: GET for tubID qivwuhf6cnon45sld7lq5a3iugsjjqmw
local#341 06:23:17.532: sendPlaintextClient: wantEncryption=True
local#342 06:23:17.585: SharemapUpdater(wtje5): starting (MODE_CHECK)
local#347 06:23:17.595: storage: slot_readv wtje5rcqexjsmyff5tysmjg66u []
local#348 06:23:17.595: returning shares [2, 3]
local#349 06:23:17.596: got result from [aty4re3a], 2 shares
local#352 06:23:17.598:  found valid version 32-es6x from aty4re3a-sh2: 5-12/590/586
local#354 06:23:17.598:  found valid version 30-gvrh from aty4re3a-sh3: 5-12/590/586
local#359 06:23:17.605: kvj2xrmm provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 0, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#360 06:23:17.611: kqyu52yz provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 687143179776L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.9.1'}
local#361 06:23:17.627: inxoy6ui provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 475073891072L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.9.1'}
local#362 06:23:17.632: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: 93a15c061ffd0b07 2\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#363 06:23:17.632: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: 93a15c061ffd0b07 2
initial-vocab-table-index: 1 bb33
local#364 06:23:17.632: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '93a15c061ffd0b07 2'}
local#365 06:23:17.632: Negotiate.switchToBanana(isClient=True)
local#366 06:23:17.632: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#367 06:23:17.632: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to g4xvpwqa] at 0x000000000272A470> won
local#368 06:23:17.632: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000272A438 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to g4xvpwqadyiwfu26qfxkgmjjxmony52p>)
local#369 06:23:17.668: got result from [hpd3hn75], 2 shares
local#372 06:23:17.668:  found valid version 32-es6x from hpd3hn75-sh3: 5-12/590/586
local#374 06:23:17.670:  found valid version 31-o7xv from hpd3hn75-sh6: 5-12/590/586
local#379 06:23:17.703: got connection to pmitrhwg, getting versions
local#380 06:23:17.726: got result from [huadamis], 1 shares
local#383 06:23:17.727:  found valid version 31-o7xv from huadamis-sh8: 5-12/590/586
local#388 06:23:17.730: got connection to baeq4skx, getting versions
local#389 06:23:17.753: got result from [b55ww7wa], 1 shares
local#392 06:23:17.753:  found valid version 32-es6x from b55ww7wa-sh10: 5-12/590/586
local#394 06:23:17.753: all queries are retired, no extra peers: done
local#395 06:23:17.753: servermap: 1*seq30-gvrh/2*seq31-o7xv/3*seq32-es6x
local#398 06:23:17.757: SharemapUpdater(wtje5): starting (MODE_READ)
local#406 06:23:17.763: storage: slot_readv wtje5rcqexjsmyff5tysmjg66u []
local#407 06:23:17.765: returning shares [2, 3]
local#408 06:23:17.766: got result from [aty4re3a], 2 shares
local#411 06:23:17.766:  found valid version 32-es6x from aty4re3a-sh2: 5-12/590/586
local#413 06:23:17.766:  found valid version 30-gvrh from aty4re3a-sh3: 5-12/590/586
local#422 06:23:17.792: Negotiation started
local#423 06:23:17.792: initClient: to target pb://vifimgiwol6shdmyoxyqvet5oz6dqnt5
local#424 06:23:17.792: sendPlaintextClient: GET for tubID vifimgiwol6shdmyoxyqvet5oz6dqnt5
local#425 06:23:17.792: sendPlaintextClient: wantEncryption=True
local#426 06:23:17.823: got result from [hpd3hn75], 2 shares
local#429 06:23:17.823:  found valid version 32-es6x from hpd3hn75-sh3: 5-12/590/586
local#431 06:23:17.825:  found valid version 31-o7xv from hpd3hn75-sh6: 5-12/590/586
local#440 06:23:17.826: got result from [b55ww7wa], 1 shares
local#443 06:23:17.826:  found valid version 32-es6x from b55ww7wa-sh10: 5-12/590/586
local#452 06:23:17.838: got result from [huadamis], 1 shares
local#455 06:23:17.839:  found valid version 31-o7xv from huadamis-sh8: 5-12/590/586
local#464 06:23:17.842: got result from [kqyu52yz], 2 shares
local#467 06:23:17.842:  found valid version 29-tdwa from kqyu52yz-sh10: 5-12/590/586
local#469 06:23:17.842:  found valid version 31-o7xv from kqyu52yz-sh4: 5-12/590/586
local#478 06:23:17.888: got connection to g4xvpwqa, getting versions
local#479 06:23:17.914: pmitrhwg provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 856782827520L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.9.1'}
local#480 06:23:17.937: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: f3d2c7eb02f4e973\r\nmy-tub-id: jbrse33y3gmtpauhhgfsrti4o4mzlcsk\r\n\r\n'
local#481 06:23:17.937: evaluateHello(isClient=True): offer={'my-tub-id': 'jbrse33y3gmtpauhhgfsrti4o4mzlcsk', 'my-incarnation': 'f3d2c7eb02f4e973', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#482 06:23:17.937: iAmTheMaster: False
local#483 06:23:17.973: got result from [kvj2xrmm], 1 shares
local#486 06:23:17.973:  found valid version 32-es6x from kvj2xrmm-sh11: 5-12/590/586
local#495 06:23:17.974: dataReceived(isClient=True,phase=0,options={}): 'HTTP/1.1 101 Switching Protocols\r\nUpgrade: TLS/1.0, PB/1.0\r\nConnection: Upgrade\r\n\r\n'
local#496 06:23:17.974: handlePLAINTEXTClient: header='HTTP/1.1 101 Switching Protocols
Upgrade: TLS/1.0, PB/1.0
Connection: Upgrade'
local#497 06:23:17.974: startENCRYPTED(isClient=True, encrypted=True)
local#498 06:23:17.974: startTLS, client=True
local#499 06:23:17.974: Negotiate.sendHello (isClient=True): {'my-incarnation': '9a6c03436c11e75e', 'last-connection': 'none 0', 'my-tub-id': 'aty4re3a3ygvb6a2gext5vbcgdzs4ihk', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#500 06:23:18.089: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: bbecd94c5a919a21\r\nmy-tub-id: gbytbnxw2hkbpjslf7mevzejefmdomtb\r\n\r\n'
local#501 06:23:18.089: evaluateHello(isClient=True): offer={'my-tub-id': 'gbytbnxw2hkbpjslf7mevzejefmdomtb', 'my-incarnation': 'bbecd94c5a919a21', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#502 06:23:18.089: iAmTheMaster: False
local#503 06:23:18.099: got result from [inxoy6ui], 1 shares
local#506 06:23:18.099:  found valid version 32-es6x from inxoy6ui-sh8: 5-12/590/586
local#508 06:23:18.099: all queries are retired, no extra peers: done
local#509 06:23:18.099: servermap: 1*seq29-tdwa/1*seq30-gvrh/3*seq31-o7xv/5*seq32-es6x
local#512 06:23:18.101: Retrieve(wtje5): starting
local#524 06:23:18.101: getting blockhashes for segment 0, share 2: set([0])
local#525 06:23:18.101: also need sharehashes for share 2: set([18, 4, 2, 7])
local#526 06:23:18.102: getting blockhashes for segment 0, share 3: set([0])
local#527 06:23:18.104: also need sharehashes for share 3: set([17, 2, 4, 7])
local#528 06:23:18.105: getting blockhashes for segment 0, share 8: set([0])
local#529 06:23:18.105: also need sharehashes for share 8: set([24, 1, 12, 6])
local#530 06:23:18.105: getting blockhashes for segment 0, share 10: set([0])
local#531 06:23:18.107: also need sharehashes for share 10: set([1, 26, 11, 6])
local#532 06:23:18.108: getting blockhashes for segment 0, share 11: set([0])
local#533 06:23:18.108: also need sharehashes for share 11: set([25, 11, 6, 1])
local#534 06:23:18.111: storage: slot_readv wtje5rcqexjsmyff5tysmjg66u [2]
local#535 06:23:18.111: returning shares [2]
local#536 06:23:18.111: storage: slot_readv wtje5rcqexjsmyff5tysmjg66u [2]
local#537 06:23:18.112: returning shares [2]
local#538 06:23:18.114: validating share 2 for segment 0
local#539 06:23:18.114: the reader gave me the following blockhashes: [0]
local#540 06:23:18.114: the reader gave me the following sharehashes: [2, 4, 18, 7]
local#541 06:23:18.114: share 2 is valid for segment 0
local#542 06:23:18.144: g4xvpwqa provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 290838614016L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#543 06:23:18.173: validating share 3 for segment 0
local#544 06:23:18.173: the reader gave me the following blockhashes: [0]
local#545 06:23:18.173: the reader gave me the following sharehashes: [17, 2, 4, 7]
local#546 06:23:18.173: share 3 is valid for segment 0
local#547 06:23:18.191: validating share 10 for segment 0
local#548 06:23:18.191: the reader gave me the following blockhashes: [0]
local#549 06:23:18.191: the reader gave me the following sharehashes: [1, 26, 11, 6]
local#550 06:23:18.193: share 10 is valid for segment 0
local#551 06:23:18.273: validating share 11 for segment 0
local#552 06:23:18.273: the reader gave me the following blockhashes: [0]
local#553 06:23:18.273: the reader gave me the following sharehashes: [1, 11, 6, 25]
local#554 06:23:18.273: share 11 is valid for segment 0
local#555 06:23:18.326: validating share 8 for segment 0
local#556 06:23:18.326: the reader gave me the following blockhashes: [0]
local#557 06:23:18.326: the reader gave me the following sharehashes: [24, 1, 12, 6]
local#558 06:23:18.326: share 8 is valid for segment 0
local#559 06:23:18.326: trying to decode and decrypt segment 0
local#560 06:23:18.326: everything looks ok, building segment 0
local#561 06:23:18.326: decoding segment 0
local#562 06:23:18.326: now decoding segment 0 of 1
local#563 06:23:18.326:  joined length 590, datalength 586
local#564 06:23:18.326:  segment len=586
local#565 06:23:18.326: decrypting segment 0
local#566 06:23:18.328: got plaintext for segment 0
local#567 06:23:18.328: stripping 0 bytes off of the first segment
local#568 06:23:18.328: original segment length: 586
local#569 06:23:18.328: new segment length: 586
local#570 06:23:18.328: adding 0 new peers to the active list
local#571 06:23:18.328: got plaintext, done
local#572 06:23:18.349: SharemapUpdater(yudiz): starting (MODE_CHECK)
local#582 06:23:18.361: baeq4skx provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 777383396864L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#583 06:23:18.375: storage: slot_readv yudizvvpuewsxzmgtvbiznak3m []
local#584 06:23:18.375: returning shares [5]
local#585 06:23:18.377: got result from [aty4re3a], 1 shares
local#588 06:23:18.378:  found valid version 14-3lsw from aty4re3a-sh5: 5-12/2405/2404
local#593 06:23:18.381: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: f3d2c7eb02f4e973 4\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#594 06:23:18.381: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: f3d2c7eb02f4e973 4
initial-vocab-table-index: 1 bb33
local#595 06:23:18.381: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'f3d2c7eb02f4e973 4'}
local#596 06:23:18.381: Negotiate.switchToBanana(isClient=True)
local#597 06:23:18.381: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#598 06:23:18.381: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to jbrse33y] at 0x0000000002723240> won
local#599 06:23:18.381: connectorFinished (<foolscap.negotiate.TubConnector object at 0x00000000027230B8 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to jbrse33y3gmtpauhhgfsrti4o4mzlcsk>)
local#600 06:23:18.424: got result from [hpd3hn75], 2 shares
local#603 06:23:18.424:  found valid version 12-n34e from hpd3hn75-sh8: 5-12/2405/2404
local#605 06:23:18.424:  found valid version 14-3lsw from hpd3hn75-sh2: 5-12/2405/2404
local#610 06:23:18.427: got result from [b55ww7wa], 0 shares
local#616 06:23:18.451: got result from [kqyu52yz], 2 shares
local#619 06:23:18.453:  found valid version 8-3p7b from kqyu52yz-sh1: 5-12/1865/1864
local#621 06:23:18.453:  found valid version 8-3p7b from kqyu52yz-sh11: 5-12/1865/1864
local#626 06:23:18.555: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: c85e879bdc30dc3f\r\nmy-tub-id: vifimgiwol6shdmyoxyqvet5oz6dqnt5\r\n\r\n'
local#627 06:23:18.555: evaluateHello(isClient=True): offer={'my-tub-id': 'vifimgiwol6shdmyoxyqvet5oz6dqnt5', 'my-incarnation': 'c85e879bdc30dc3f', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#628 06:23:18.555: iAmTheMaster: False
local#629 06:23:18.569: got result from [inxoy6ui], 0 shares
local#635 06:23:18.605: got result from [kvj2xrmm], 1 shares
local#638 06:23:18.605:  found valid version 14-3lsw from kvj2xrmm-sh7: 5-12/2405/2404
local#643 06:23:18.605: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: bbecd94c5a919a21 2\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#644 06:23:18.605: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: bbecd94c5a919a21 2
initial-vocab-table-index: 1 bb33
local#645 06:23:18.605: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'bbecd94c5a919a21 2'}
local#646 06:23:18.605: Negotiate.switchToBanana(isClient=True)
local#647 06:23:18.605: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#648 06:23:18.605: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to gbytbnxw] at 0x00000000027237F0> won
local#649 06:23:18.605: connectorFinished (<foolscap.negotiate.TubConnector object at 0x0000000002723780 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to gbytbnxw2hkbpjslf7mevzejefmdomtb>)
local#650 06:23:18.607: got connection to jbrse33y, getting versions
local#651 06:23:18.650: got result from [g4xvpwqa], 1 shares
local#654 06:23:18.651:  found valid version 14-3lsw from g4xvpwqa-sh9: 5-12/2405/2404
local#659 06:23:18.653: got result from [huadamis], 1 shares
local#662 06:23:18.653:  found valid version 14-3lsw from huadamis-sh8: 5-12/2405/2404
local#665 06:23:18.653: _check_for_done, mode is 'MODE_CHECK', 1 queries outstanding, 0 extra peers available, 1 'must query' peers left, need_privkey=False
local#666 06:23:18.653: 1 'must query' peers left
local#667 06:23:18.655: dataReceived(isClient=True,phase=0,options={}): 'HTTP/1.1 101 Switching Protocols\r\nUpgrade: TLS/1.0, PB/1.0\r\nConnection: Upgrade\r\n\r\n'
local#668 06:23:18.655: handlePLAINTEXTClient: header='HTTP/1.1 101 Switching Protocols
Upgrade: TLS/1.0, PB/1.0
Connection: Upgrade'
local#669 06:23:18.655: startENCRYPTED(isClient=True, encrypted=True)
local#670 06:23:18.655: startTLS, client=True
local#671 06:23:18.655: Negotiate.sendHello (isClient=True): {'my-incarnation': '9a6c03436c11e75e', 'last-connection': 'none 0', 'my-tub-id': 'aty4re3a3ygvb6a2gext5vbcgdzs4ihk', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#672 06:23:18.822: jbrse33y provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'maximum-immutable-share-size': 217038468608L, 'tolerates-immutable-read-overrun': True, 'delete-mutable-shares-with-zero-length-writev': True}, 'application-version': 'allmydata-tahoe/1.8.2'}
local#673 06:23:18.865: got result from [pmitrhwg], 1 shares
local#674 06:23:18.865: _got_results done
local#675 06:23:18.865: _got_results: got shnum #4 from peerid pmitrhwg
local#676 06:23:18.865:  found valid version 14-3lsw from pmitrhwg-sh4: 5-12/2405/2404
local#677 06:23:18.865: _check_for_done, mode is 'MODE_CHECK', 0 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#678 06:23:18.865: all queries are retired, no extra peers: done
local#679 06:23:18.865: servermap: 1*seq12-n34e/6*seq14-3lsw/2*seq8-3p7b
local#680 06:23:18.865: _check_for_done, mode is 'MODE_CHECK', 0 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#681 06:23:18.865: but we're not running
local#682 06:23:18.868: SharemapUpdater(yudiz): starting (MODE_READ)
local#683 06:23:18.868: sending query to [hpd3hn75], readsize=4000
local#684 06:23:18.868: sending query to [huadamis], readsize=4000
local#685 06:23:18.868: sending query to [baeq4skx], readsize=4000
local#686 06:23:18.869: sending query to [kvj2xrmm], readsize=4000
local#687 06:23:18.869: sending query to [b55ww7wa], readsize=4000
local#688 06:23:18.871: sending query to [inxoy6ui], readsize=4000
local#689 06:23:18.871: sending query to [kqyu52yz], readsize=4000
local#690 06:23:18.871: sending query to [aty4re3a], readsize=4000
local#691 06:23:18.874: storage: slot_readv yudizvvpuewsxzmgtvbiznak3m []
local#692 06:23:18.875: returning shares [5]
local#693 06:23:18.875: got result from [aty4re3a], 1 shares
local#694 06:23:18.877: _got_results done
local#695 06:23:18.877: _got_results: got shnum #5 from peerid aty4re3a
local#696 06:23:18.877:  found valid version 14-3lsw from aty4re3a-sh5: 5-12/2405/2404
local#697 06:23:18.877: _check_for_done, mode is 'MODE_READ', 7 queries outstanding, 3 extra peers available, 0 'must query' peers left, need_privkey=False
local#698 06:23:18.877: 1 completed, 8 to query: need more
local#699 06:23:18.877:  there are 7 queries outstanding
local#700 06:23:18.877: sending 0 more queries: 
local#701 06:23:18.877: _check_for_done, mode is 'MODE_READ', 7 queries outstanding, 3 extra peers available, 0 'must query' peers left, need_privkey=False
local#702 06:23:18.877: 1 completed, 8 to query: need more
local#703 06:23:18.877:  there are 7 queries outstanding
local#704 06:23:18.877: sending 0 more queries: 
local#705 06:23:18.924: got connection to gbytbnxw, getting versions
local#706 06:23:18.934: got result from [hpd3hn75], 2 shares
local#707 06:23:18.934: _got_results done
local#708 06:23:18.934: _got_results: got shnum #8 from peerid hpd3hn75
local#709 06:23:18.934:  found valid version 12-n34e from hpd3hn75-sh8: 5-12/2405/2404
local#710 06:23:18.934: _got_results: got shnum #2 from peerid hpd3hn75
local#711 06:23:18.934:  found valid version 14-3lsw from hpd3hn75-sh2: 5-12/2405/2404
local#712 06:23:18.934: _check_for_done, mode is 'MODE_READ', 6 queries outstanding, 3 extra peers available, 0 'must query' peers left, need_privkey=False
local#713 06:23:18.934: 2 completed, 8 to query: need more
local#714 06:23:18.934:  there are 6 queries outstanding
local#715 06:23:18.934: sending 0 more queries: 
local#716 06:23:18.934: _check_for_done, mode is 'MODE_READ', 6 queries outstanding, 3 extra peers available, 0 'must query' peers left, need_privkey=False
local#717 06:23:18.934: 2 completed, 8 to query: need more
local#718 06:23:18.934:  there are 6 queries outstanding
local#719 06:23:18.934: sending 0 more queries: 
local#720 06:23:18.937: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: c85e879bdc30dc3f 2\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#721 06:23:18.937: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: c85e879bdc30dc3f 2
initial-vocab-table-index: 1 bb33
local#722 06:23:18.937: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'c85e879bdc30dc3f 2'}
local#723 06:23:18.937: Negotiate.switchToBanana(isClient=True)
local#724 06:23:18.937: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#725 06:23:18.937: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to vifimgiw] at 0x000000000272A2E8> won
local#726 06:23:18.937: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000272A2B0 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to vifimgiwol6shdmyoxyqvet5oz6dqnt5>)
local#727 06:23:18.941: got result from [b55ww7wa], 0 shares
local#728 06:23:18.941: _check_for_done, mode is 'MODE_READ', 5 queries outstanding, 3 extra peers available, 0 'must query' peers left, need_privkey=False
local#729 06:23:18.941: 3 completed, 8 to query: need more
local#730 06:23:18.941:  there are 5 queries outstanding
local#731 06:23:18.943: sending 0 more queries: 
local#732 06:23:18.943: _got_results done
local#733 06:23:18.943: _check_for_done, mode is 'MODE_READ', 5 queries outstanding, 3 extra peers available, 0 'must query' peers left, need_privkey=False
local#734 06:23:18.943: 3 completed, 8 to query: need more
local#735 06:23:18.943:  there are 5 queries outstanding
local#736 06:23:18.943: sending 0 more queries: 
local#737 06:23:18.963: got result from [huadamis], 1 shares
local#738 06:23:18.964: _got_results done
local#739 06:23:18.964: _got_results: got shnum #8 from peerid huadamis
local#740 06:23:18.964:  found valid version 14-3lsw from huadamis-sh8: 5-12/2405/2404
local#741 06:23:18.964: _check_for_done, mode is 'MODE_READ', 4 queries outstanding, 3 extra peers available, 0 'must query' peers left, need_privkey=False
local#742 06:23:18.964: 4 completed, 8 to query: need more
local#743 06:23:18.964:  there are 4 queries outstanding
local#744 06:23:18.964:  there are 4 queries outstanding
local#745 06:23:18.964: sending 1 more queries: [g4xvpwqa]
local#746 06:23:18.964: sending query to [g4xvpwqa], readsize=4000
local#747 06:23:18.966: _check_for_done, mode is 'MODE_READ', 5 queries outstanding, 2 extra peers available, 0 'must query' peers left, need_privkey=False
local#748 06:23:18.966: 4 completed, 8 to query: need more
local#749 06:23:18.966:  there are 5 queries outstanding
local#750 06:23:18.966: sending 0 more queries: 
local#751 06:23:19.017: got result from [kqyu52yz], 2 shares
local#752 06:23:19.019: _got_results done
local#753 06:23:19.019: _got_results: got shnum #1 from peerid kqyu52yz
local#754 06:23:19.019:  found valid version 8-3p7b from kqyu52yz-sh1: 5-12/1865/1864
local#755 06:23:19.019: _got_results: got shnum #11 from peerid kqyu52yz
local#756 06:23:19.019:  found valid version 8-3p7b from kqyu52yz-sh11: 5-12/1865/1864
local#757 06:23:19.019: _check_for_done, mode is 'MODE_READ', 4 queries outstanding, 2 extra peers available, 0 'must query' peers left, need_privkey=False
local#758 06:23:19.019: 5 completed, 8 to query: need more
local#759 06:23:19.019:  there are 4 queries outstanding
local#760 06:23:19.019:  there are 4 queries outstanding
local#761 06:23:19.019: sending 1 more queries: [jbrse33y]
local#762 06:23:19.019: sending query to [jbrse33y], readsize=4000
local#763 06:23:19.019: _check_for_done, mode is 'MODE_READ', 5 queries outstanding, 1 extra peers available, 0 'must query' peers left, need_privkey=False
local#764 06:23:19.020: 5 completed, 8 to query: need more
local#765 06:23:19.020:  there are 5 queries outstanding
local#766 06:23:19.020: sending 0 more queries: 
local#767 06:23:19.046: got result from [kvj2xrmm], 1 shares
local#768 06:23:19.048: _got_results done
local#769 06:23:19.048: _got_results: got shnum #7 from peerid kvj2xrmm
local#770 06:23:19.048:  found valid version 14-3lsw from kvj2xrmm-sh7: 5-12/2405/2404
local#771 06:23:19.048: _check_for_done, mode is 'MODE_READ', 4 queries outstanding, 1 extra peers available, 0 'must query' peers left, need_privkey=False
local#772 06:23:19.048: 6 completed, 8 to query: need more
local#773 06:23:19.048:  there are 4 queries outstanding
local#774 06:23:19.048:  there are 4 queries outstanding
local#775 06:23:19.048: sending 1 more queries: [pmitrhwg]
local#776 06:23:19.048: sending query to [pmitrhwg], readsize=4000
local#777 06:23:19.049: _check_for_done, mode is 'MODE_READ', 5 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#778 06:23:19.049: 6 completed, 8 to query: need more
local#779 06:23:19.049:  there are 5 queries outstanding
local#780 06:23:19.049: sending 0 more queries: 
local#781 06:23:19.055: got result from [inxoy6ui], 0 shares
local#782 06:23:19.055: _check_for_done, mode is 'MODE_READ', 4 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#783 06:23:19.055: 7 completed, 8 to query: need more
local#784 06:23:19.055:  there are 4 queries outstanding
local#785 06:23:19.055: sending 0 more queries: 
local#786 06:23:19.055: _got_results done
local#787 06:23:19.055: _check_for_done, mode is 'MODE_READ', 4 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#788 06:23:19.055: 7 completed, 8 to query: need more
local#789 06:23:19.055:  there are 4 queries outstanding
local#790 06:23:19.055: sending 0 more queries: 
local#791 06:23:19.114: got result from [baeq4skx], 1 shares
local#792 06:23:19.114: _got_results done
local#793 06:23:19.114: _got_results: got shnum #6 from peerid baeq4skx
local#794 06:23:19.114:  found valid version 14-3lsw from baeq4skx-sh6: 5-12/2405/2404
local#795 06:23:19.114: _check_for_done, mode is 'MODE_READ', 3 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#796 06:23:19.114: no higher-seqnum: done
local#797 06:23:19.114: servermap: 1*seq12-n34e/5*seq14-3lsw/2*seq8-3p7b
local#798 06:23:19.115: _check_for_done, mode is 'MODE_READ', 3 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#799 06:23:19.115: but we're not running
local#800 06:23:19.115: Retrieve(yudiz): starting
local#801 06:23:19.115: got seqnum 14
local#802 06:23:19.115: got encoding parameters: k: 5 n: 12 1 segments of 2405 bytes each (2405 byte tail segment)
local#803 06:23:19.115: starting download
local#804 06:23:19.115: adding 5 new peers to the active list
local#805 06:23:19.115: added reader for share 2
local#806 06:23:19.115: added reader for share 5
local#807 06:23:19.117: added reader for share 6
local#808 06:23:19.117: added reader for share 7
local#809 06:23:19.118: added reader for share 8
local#810 06:23:19.118: on segment 1 of 1
local#811 06:23:19.118: processing segment 0
local#812 06:23:19.118: getting blockhashes for segment 0, share 2: set([0])
local#813 06:23:19.119: also need sharehashes for share 2: set([18, 4, 2, 7])
local#814 06:23:19.121: getting blockhashes for segment 0, share 5: set([0])
local#815 06:23:19.121: also need sharehashes for share 5: set([19, 10, 3, 2])
local#816 06:23:19.122: getting blockhashes for segment 0, share 6: set([0])
local#817 06:23:19.124: also need sharehashes for share 6: set([9, 2, 3, 22])
local#818 06:23:19.125: getting blockhashes for segment 0, share 7: set([0])
local#819 06:23:19.125: also need sharehashes for share 7: set([9, 2, 3, 21])
local#820 06:23:19.128: getting blockhashes for segment 0, share 8: set([0])
local#821 06:23:19.128: also need sharehashes for share 8: set([24, 1, 12, 6])
local#822 06:23:19.132: storage: slot_readv yudizvvpuewsxzmgtvbiznak3m [5]
local#823 06:23:19.132: returning shares [5]
local#824 06:23:19.134: storage: slot_readv yudizvvpuewsxzmgtvbiznak3m [5]
local#825 06:23:19.134: returning shares [5]
local#826 06:23:19.134: storage: slot_readv yudizvvpuewsxzmgtvbiznak3m [5]
local#827 06:23:19.134: returning shares [5]
local#828 06:23:19.134: storage: slot_readv yudizvvpuewsxzmgtvbiznak3m [5]
local#829 06:23:19.135: returning shares [5]
local#830 06:23:19.135: got connection to vifimgiw, getting versions
local#831 06:23:19.137: got valid privkey from shnum 5 on reader <allmydata.mutable.layout.MDMFSlotReadProxy instance at 0x0000000004B96AC8>
local#832 06:23:19.138: validating share 5 for segment 0
local#833 06:23:19.138: the reader gave me the following blockhashes: [0]
local#834 06:23:19.138: the reader gave me the following sharehashes: [19, 2, 3, 10]
local#835 06:23:19.138: share 5 is valid for segment 0
local#836 06:23:19.197: got valid privkey from shnum 2 on reader <allmydata.mutable.layout.MDMFSlotReadProxy instance at 0x0000000004B96A88>
local#837 06:23:19.197: validating share 2 for segment 0
local#838 06:23:19.197: the reader gave me the following blockhashes: [0]
local#839 06:23:19.197: the reader gave me the following sharehashes: [2, 4, 18, 7]
local#840 06:23:19.198: share 2 is valid for segment 0
local#841 06:23:19.240: got result from [g4xvpwqa], 1 shares
local#842 06:23:19.240: but we're not running, so we'll ignore it
local#843 06:23:19.240: _check_for_done, mode is 'MODE_READ', 2 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#844 06:23:19.240: but we're not running
local#845 06:23:19.263: got valid privkey from shnum 7 on reader <allmydata.mutable.layout.MDMFSlotReadProxy instance at 0x0000000004B96A08>
local#846 06:23:19.263: validating share 7 for segment 0
local#847 06:23:19.263: the reader gave me the following blockhashes: [0]
local#848 06:23:19.263: the reader gave me the following sharehashes: [9, 2, 3, 21]
local#849 06:23:19.263: share 7 is valid for segment 0
local#850 06:23:19.339: got valid privkey from shnum 8 on reader <allmydata.mutable.layout.MDMFSlotReadProxy instance at 0x0000000004B969C8>
local#851 06:23:19.341: validating share 8 for segment 0
local#852 06:23:19.341: the reader gave me the following blockhashes: [0]
local#853 06:23:19.341: the reader gave me the following sharehashes: [24, 1, 12, 6]
local#854 06:23:19.341: share 8 is valid for segment 0
local#855 06:23:19.342: vifimgiw provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 981054612992L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#856 06:23:19.345: got valid privkey from shnum 6 on reader <allmydata.mutable.layout.MDMFSlotReadProxy instance at 0x0000000004B96A48>
local#857 06:23:19.345: validating share 6 for segment 0
local#858 06:23:19.345: the reader gave me the following blockhashes: [0]
local#859 06:23:19.345: the reader gave me the following sharehashes: [9, 2, 3, 22]
local#860 06:23:19.345: share 6 is valid for segment 0
local#861 06:23:19.345: trying to decode and decrypt segment 0
local#862 06:23:19.345: everything looks ok, building segment 0
local#863 06:23:19.345: decoding segment 0
local#864 06:23:19.345: now decoding segment 0 of 1
local#865 06:23:19.345:  joined length 2405, datalength 2404
local#866 06:23:19.345:  segment len=2404
local#867 06:23:19.345: decrypting segment 0
local#868 06:23:19.345: got plaintext for segment 0
local#869 06:23:19.345: stripping 0 bytes off of the first segment
local#870 06:23:19.345: original segment length: 2404
local#871 06:23:19.345: new segment length: 2404
local#872 06:23:19.345: adding 0 new peers to the active list
local#873 06:23:19.345: got plaintext, done
local#874 06:23:19.346: Publish(yudiz): starting
local#875 06:23:19.346: starting publish, datalen is 2404
local#876 06:23:19.346: new seqnum will be 15
local#877 06:23:19.346: building encoding parameters for file
local#878 06:23:19.346: got segsize 2405
local#879 06:23:19.346: got 1 segments
local#880 06:23:19.346: got tail segment size 2404
local#881 06:23:19.346: got start segment 0
local#882 06:23:19.346: got end segment 0
local#883 06:23:19.346: current goal: before update: , sh1 to [kqyu52yz], sh2 to [hpd3hn75], sh4 to [pmitrhwg], sh5 to [aty4re3a], sh7 to [kvj2xrmm], sh8 to [hpd3hn75], sh8 to [huadamis], sh9 to [g4xvpwqa], sh11 to [kqyu52yz]
local#884 06:23:19.346: we are planning to push new seqnum=#15
local#885 06:23:19.348: current goal: after update: , sh0 to [inxoy6ui], sh1 to [kqyu52yz], sh2 to [hpd3hn75], sh3 to [b55ww7wa], sh4 to [pmitrhwg], sh5 to [aty4re3a], sh6 to [baeq4skx], sh7 to [kvj2xrmm], sh8 to [hpd3hn75], sh8 to [huadamis], sh9 to [g4xvpwqa], sh10 to [jbrse33y], sh11 to [kqyu52yz]
local#886 06:23:19.348: we are planning to push new seqnum=#15
local#887 06:23:19.348: Starting push
local#888 06:23:19.348: Pushing segment 1 of 1
local#889 06:23:19.375: storage: slot_writev yudizvvpuewsxzmgtvbiznak3m
local#890 06:23:19.378: _got_write_answer from aty4re3a, share 5
local#891 06:23:19.380: found the following surprise shares: set([])
local#892 06:23:19.380: wrote successfully: adding new share to servermap
local#893 06:23:19.403: got result from [jbrse33y], 1 shares
local#894 06:23:19.403: but we're not running, so we'll ignore it
local#895 06:23:19.403: _check_for_done, mode is 'MODE_READ', 1 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#896 06:23:19.403: but we're not running
local#897 06:23:19.403: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\ninitial-vocab-table-range: 0 1\r\nmy-incarnation: 4bd27a164f4d2704\r\nmy-tub-id: qivwuhf6cnon45sld7lq5a3iugsjjqmw\r\n\r\n'
local#898 06:23:19.403: evaluateHello(isClient=True): offer={'my-tub-id': 'qivwuhf6cnon45sld7lq5a3iugsjjqmw', 'my-incarnation': '4bd27a164f4d2704', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
local#899 06:23:19.403: iAmTheMaster: False
local#900 06:23:19.453: _got_write_answer from hpd3hn75, share 2
local#901 06:23:19.453: found the following surprise shares: set([8])
local#902 06:23:19.453: they had shares [8] that we didn't know about [INCIDENT-TRIGGER]
local#903 06:23:19.612: wrote successfully: adding new share to servermap
local#904 06:23:19.614: _got_write_answer from kvj2xrmm, share 7
local#905 06:23:19.614: found the following surprise shares: set([])
local#906 06:23:19.615: wrote successfully: adding new share to servermap
local#907 06:23:19.615: _got_write_answer from jbrse33y, share 10
local#908 06:23:19.615: found the following surprise shares: set([])
local#909 06:23:19.615: our testv failed, so the write did not happen
local#910 06:23:19.615: _got_write_answer from baeq4skx, share 6
local#911 06:23:19.615: found the following surprise shares: set([])
local#912 06:23:19.615: our testv failed, so the write did not happen
local#913 06:23:19.617: _got_write_answer from kqyu52yz, share 1
local#914 06:23:19.617: found the following surprise shares: set([])
local#915 06:23:19.617: wrote successfully: adding new share to servermap
local#916 06:23:19.617: _got_write_answer from kqyu52yz, share 11
local#917 06:23:19.617: found the following surprise shares: set([])
local#918 06:23:19.617: wrote successfully: adding new share to servermap
local#919 06:23:19.618: _got_write_answer from b55ww7wa, share 3
local#920 06:23:19.618: found the following surprise shares: set([])
local#921 06:23:19.618: wrote successfully: adding new share to servermap
local#922 06:23:19.618: _got_write_answer from huadamis, share 8
local#923 06:23:19.618: found the following surprise shares: set([])
local#924 06:23:19.618: wrote successfully: adding new share to servermap
local#925 06:23:19.674: _got_write_answer from g4xvpwqa, share 9
local#926 06:23:19.674: found the following surprise shares: set([])
local#927 06:23:19.674: wrote successfully: adding new share to servermap
local#928 06:23:19.680: _got_write_answer from inxoy6ui, share 0
local#929 06:23:19.680: found the following surprise shares: set([])
local#930 06:23:19.680: wrote successfully: adding new share to servermap
local#931 06:23:19.855: dataReceived(isClient=True,phase=2,options={}): 'banana-decision-version: 3\r\ncurrent-connection: 4bd27a164f4d2704 4\r\ninitial-vocab-table-index: 1 bb33\r\n\r\n'
local#932 06:23:19.855: handleDECIDING(isClient=True): banana-decision-version: 3
current-connection: 4bd27a164f4d2704 4
initial-vocab-table-index: 1 bb33
local#933 06:23:19.855: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '4bd27a164f4d2704 4'}
local#934 06:23:19.855: Negotiate.switchToBanana(isClient=True)
local#935 06:23:19.855: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
local#936 06:23:19.857: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from aty4re3a] [to qivwuhf6] at 0x000000000272A6D8> won
local#937 06:23:19.857: connectorFinished (<foolscap.negotiate.TubConnector object at 0x000000000272A668 from aty4re3a3ygvb6a2gext5vbcgdzs4ihk to qivwuhf6cnon45sld7lq5a3iugsjjqmw>)
local#938 06:23:19.931: gbytbnxw provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 294346153984L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.7.1'}
local#939 06:23:20.088: got connection to qivwuhf6, getting versions
local#940 06:23:20.206: got result from [pmitrhwg], 1 shares
local#941 06:23:20.206: but we're not running, so we'll ignore it
local#942 06:23:20.206: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra peers available, 0 'must query' peers left, need_privkey=False
local#943 06:23:20.206: but we're not running
local#944 06:23:20.328: qivwuhf6 provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'delete-mutable-shares-with-zero-length-writev': True, 'maximum-immutable-share-size': 901918483968L, 'fills-holes-with-zero-bytes': True, 'tolerates-immutable-read-overrun': True, 'prevents-read-past-end-of-share-data': True}, 'application-version': 'allmydata-tahoe/1.8.3'}
local#945 06:23:20.391: _got_write_answer from pmitrhwg, share 4
local#946 06:23:20.391: found the following surprise shares: set([])
local#947 06:23:20.391: wrote successfully: adding new share to servermap
local#948 06:23:20.391: Publish failed with UncoordinatedWriteError
local#949 06:23:20.392: web: 127.0.0.1 POST /uri/[CENSORED]..?t=stream-deep-check&repair=true&add-lease=true 200 2703
local#950 06:23:21.713: None
local#951 06:23:21.808: web: 127.0.0.1 GET / 200 13292