tahoe-lafs
/
trac-2024-07-25
2
0
Issues 1.1k Wiki

backup stopped with "UnrecoverableFileError:" #2482

New Issue
Closed
opened 2015-08-14 21:17:49 +00:00 by zooko · 14 comments
zooko commented 2015-08-14 21:17:49 +00:00
Copy Link

The tail end of the output from time tahoe backup -v -v -v . papers: is:

skipping '/papers/incoming-on-sparkn/what-must-i-do-to-get-well-by-elma-stuart.pdf'..
skipping '/papers/incoming-on-sparkn/sullivan2015(1).pdf'..
skipping '/papers/incoming-on-sparkn/cai2015.pdf'..
skipping '/papers/incoming-on-sparkn/10.1038@nn.3922.pdf'..
uploading '/papers/incoming-on-sparkn/JCI6223(1).pdf'..
 /papers/incoming-on-sparkn/JCI6223(1).pdf -> URI:CHK:phankodobfvdzqb22x52gqrbpe:2no43tgyrd2jbtnq33axkhe6mosj5bpno6cyqf4ivhmgzbule7kq:1:1:312823
uploading '/papers/incoming-on-sparkn/Onodera-2014-“Increased sugar uptake promotes oncogenesis via EPAC⁄RAP1 and O-GlcNAc pathways”.pdf'..
 /papers/incoming-on-sparkn/Onodera-2014-“Increased sugar uptake promotes oncogenesis via EPAC⁄RAP1 and O-GlcNAc pathways”.pdf -> URI:CHK:gkqgvv4wvjkasviugffnwjcik4:yi4midal3fap7mlquk2vuntxjmqwyloeprspdbgyrz5eic7smsza:1:1:6531824
uploading '/papers/incoming-on-sparkn/Reaven-2003-“Insulin Resistance and Compensatory Hyperinsulinemia — The Key Player Between Cigarette Smoking and Cardiovascular Disease?”.pdf'..
 /papers/incoming-on-sparkn/Reaven-2003-“Insulin Resistance and Compensatory Hyperinsulinemia — The Key Player Between Cigarette Smoking and Cardiovascular Disease?”.pdf -> URI:CHK:qid72hqugoeuzbt3hk2m5kdseu:mhvkanviylb3qggewvhlpa6dykxjbwjlocimho7zalkqfzmjfsrq:1:1:60275
uploading '/papers/incoming-on-sparkn/Nebeling-1992-“Effects of dietary-induced ketosis on tumor metabolism, nutritional status, and quality of life in pediatric oncology patients (dissertation)”.pdf'..
 /papers/incoming-on-sparkn/Nebeling-1992-“Effects of dietary-induced ketosis on tumor metabolism, nutritional status, and quality of life in pediatric oncology patients (dissertation)”.pdf -> URI:CHK:kltjnhayfnedca57yazlkhpmte:wsovdpmlmjv4wvyw2ttro5c7ptzoxlurz35qaez3vbqlhuwvx4iq:1:1:8519379
uploading '/papers/incoming-on-sparkn/Poff-2014-“Ketone supplementation decreases tumor cell viability and prolongs survival of mice with metastatic cancer”.pdf'..
 /papers/incoming-on-sparkn/Poff-2014-“Ketone supplementation decreases tumor cell viability and prolongs survival of mice with metastatic cancer”.pdf -> URI:CHK:pxtlbru3ayigforsgkfn7epigm:zt5vv466ybahzfnmhrnsn6sntnvvltgdlxwu3azdti3qutewv42a:1:1:645271
uploading '/papers/incoming-on-sparkn/Wang-2015-“Hyperbaric oxygen promotes malignant glioma cell growth and inhibits cell apoptosis”.pdf'..
 /papers/incoming-on-sparkn/Wang-2015-“Hyperbaric oxygen promotes malignant glioma cell growth and inhibits cell apoptosis”.pdf -> URI:CHK:j7k4uwglqrm7zj3qsu5ujr6bay:svawden2m62l2wtougbv5ati4jj6yermlogsfwnltbaxvcprosqq:1:1:1293042
 creating directory for '/papers/incoming-on-sparkn'
 creating directory for '/papers'
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 160, in run
    rc = runner(sys.argv[1:], install_node_control=install_node_control)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 145, in runner
    rc = cli.dispatch[command](so)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/cli.py", line 543, in backup
    rc = tahoe_backup.backup(options)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 326, in backup
    return bu.run()
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 123, in run
    put_child(archives_url, now, new_backup_dircap)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 57, in put_child
    raise HTTPError("Error during put_child", resp)
HTTPError: Error during put_child: 410 Gone
UnrecoverableFileError: the directory (or mutable file) could not be retrieved, because there were insufficient good shares. This might indicate that no servers were connected, insufficient servers were connected, the URI was corrupt, or that shares have been lost due to server departure, hard drive failure, or disk corruption. You should perform a filecheck on this object to learn more.

real    0m47.078s
user    0m0.892s
sys     0m0.334s

The version of Tahoe-LAFS is:

allmydata-tahoe: 1.10.1 [master: 2875a9ffc415cd665026419001f2311b4efd44e1]
foolscap: 0.8.0
pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958
zfec: 1.4.24
Twisted: 15.0.0
Nevow: 0.11.1
zope.interface: unknown
python: 2.7.6
platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF
pyOpenSSL: 0.13
OpenSSL: 1.0.1f [6 Jan 2014]
simplejson: 3.3.1
pycrypto: 2.6.1
pyasn1: 0.1.7
mock: 1.0.1
service-identity: 14.0.0
characteristic: 14.3.0
pyasn1-modules: 0.0.5
setuptools: 3.3
The tail end of the output from `time tahoe backup -v -v -v . papers:` is: ``` skipping '/papers/incoming-on-sparkn/what-must-i-do-to-get-well-by-elma-stuart.pdf'.. skipping '/papers/incoming-on-sparkn/sullivan2015(1).pdf'.. skipping '/papers/incoming-on-sparkn/cai2015.pdf'.. skipping '/papers/incoming-on-sparkn/10.1038@nn.3922.pdf'.. uploading '/papers/incoming-on-sparkn/JCI6223(1).pdf'.. /papers/incoming-on-sparkn/JCI6223(1).pdf -> URI:CHK:phankodobfvdzqb22x52gqrbpe:2no43tgyrd2jbtnq33axkhe6mosj5bpno6cyqf4ivhmgzbule7kq:1:1:312823 uploading '/papers/incoming-on-sparkn/Onodera-2014-“Increased sugar uptake promotes oncogenesis via EPAC⁄RAP1 and O-GlcNAc pathways”.pdf'.. /papers/incoming-on-sparkn/Onodera-2014-“Increased sugar uptake promotes oncogenesis via EPAC⁄RAP1 and O-GlcNAc pathways”.pdf -> URI:CHK:gkqgvv4wvjkasviugffnwjcik4:yi4midal3fap7mlquk2vuntxjmqwyloeprspdbgyrz5eic7smsza:1:1:6531824 uploading '/papers/incoming-on-sparkn/Reaven-2003-“Insulin Resistance and Compensatory Hyperinsulinemia — The Key Player Between Cigarette Smoking and Cardiovascular Disease?”.pdf'.. /papers/incoming-on-sparkn/Reaven-2003-“Insulin Resistance and Compensatory Hyperinsulinemia — The Key Player Between Cigarette Smoking and Cardiovascular Disease?”.pdf -> URI:CHK:qid72hqugoeuzbt3hk2m5kdseu:mhvkanviylb3qggewvhlpa6dykxjbwjlocimho7zalkqfzmjfsrq:1:1:60275 uploading '/papers/incoming-on-sparkn/Nebeling-1992-“Effects of dietary-induced ketosis on tumor metabolism, nutritional status, and quality of life in pediatric oncology patients (dissertation)”.pdf'.. /papers/incoming-on-sparkn/Nebeling-1992-“Effects of dietary-induced ketosis on tumor metabolism, nutritional status, and quality of life in pediatric oncology patients (dissertation)”.pdf -> URI:CHK:kltjnhayfnedca57yazlkhpmte:wsovdpmlmjv4wvyw2ttro5c7ptzoxlurz35qaez3vbqlhuwvx4iq:1:1:8519379 uploading '/papers/incoming-on-sparkn/Poff-2014-“Ketone supplementation decreases tumor cell viability and prolongs survival of mice with metastatic cancer”.pdf'.. /papers/incoming-on-sparkn/Poff-2014-“Ketone supplementation decreases tumor cell viability and prolongs survival of mice with metastatic cancer”.pdf -> URI:CHK:pxtlbru3ayigforsgkfn7epigm:zt5vv466ybahzfnmhrnsn6sntnvvltgdlxwu3azdti3qutewv42a:1:1:645271 uploading '/papers/incoming-on-sparkn/Wang-2015-“Hyperbaric oxygen promotes malignant glioma cell growth and inhibits cell apoptosis”.pdf'.. /papers/incoming-on-sparkn/Wang-2015-“Hyperbaric oxygen promotes malignant glioma cell growth and inhibits cell apoptosis”.pdf -> URI:CHK:j7k4uwglqrm7zj3qsu5ujr6bay:svawden2m62l2wtougbv5ati4jj6yermlogsfwnltbaxvcprosqq:1:1:1293042 creating directory for '/papers/incoming-on-sparkn' creating directory for '/papers' Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 160, in run rc = runner(sys.argv[1:], install_node_control=install_node_control) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 145, in runner rc = cli.dispatch[command](so) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/cli.py", line 543, in backup rc = tahoe_backup.backup(options) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 326, in backup return bu.run() File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 123, in run put_child(archives_url, now, new_backup_dircap) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 57, in put_child raise HTTPError("Error during put_child", resp) HTTPError: Error during put_child: 410 Gone UnrecoverableFileError: the directory (or mutable file) could not be retrieved, because there were insufficient good shares. This might indicate that no servers were connected, insufficient servers were connected, the URI was corrupt, or that shares have been lost due to server departure, hard drive failure, or disk corruption. You should perform a filecheck on this object to learn more. real 0m47.078s user 0m0.892s sys 0m0.334s ``` The version of Tahoe-LAFS is: ``` allmydata-tahoe: 1.10.1 [master: 2875a9ffc415cd665026419001f2311b4efd44e1] foolscap: 0.8.0 pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958 zfec: 1.4.24 Twisted: 15.0.0 Nevow: 0.11.1 zope.interface: unknown python: 2.7.6 platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF pyOpenSSL: 0.13 OpenSSL: 1.0.1f [6 Jan 2014] simplejson: 3.3.1 pycrypto: 2.6.1 pyasn1: 0.1.7 mock: 1.0.1 service-identity: 14.0.0 characteristic: 14.3.0 pyasn1-modules: 0.0.5 setuptools: 3.3 ```
zooko added the
code
normal
defect
1.10.1
 labels 2015-08-14 21:17:49 +00:00
zooko added this to the undecided milestone 2015-08-14 21:17:49 +00:00
zooko commented 2015-08-14 21:18:41 +00:00
Author
Copy Link

Attachment flog-catchup.flog (242436 bytes) added

**Attachment** flog-catchup.flog (242436 bytes) added
flog-catchup.flog
237 KiB
zooko commented 2015-08-14 21:20:55 +00:00
Author
Copy Link

I just uploaded flog-catchup.flog, which resulted from using this command: time tahoe debug flogtool tail --verbose --catch-up --save-to=flog-catchup.flog --timestamps=utc ~/.tahoe/private/logport.furl. If you look at that file with flogtool dump --timestamps=utc, it outputs this:

Application versions (embedded in logfile):
           Nevow: 0.11.1
         OpenSSL: 1.0.1f
         Twisted: 15.0.0
 allmydata-tahoe: 1.10.1
  characteristic: 14.3.0
        foolscap: 0.8.0
            mock: 1.0.1
        platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF
       pyOpenSSL: 0.13
          pyasn1: 0.1.7
  pyasn1-modules: 0.0.5
        pycrypto: 2.6.1
      pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958
          python: 2.7.6
service-identity: 14.0.0
      setuptools: 3.3
      simplejson: 3.3.1
         twisted: 15.0.0
            zfec: 1.4.24
  zope.interface: unknown
PID: 18820

gzi2nwh4#0 2015-08-14_19:58:11.468818Z: Node constructed. allmydata-tahoe: 1.10.1 [master: 2875a9ffc415cd665026419001f2311b4efd44e1]
foolscap: 0.8.0
pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958
zfec: 1.4.24
Twisted: 15.0.0
Nevow: 0.11.1
zope.interface: unknown
python: 2.7.6
platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF
pyOpenSSL: 0.13
OpenSSL: 1.0.1f [6 Jan 2014]
simplejson: 3.3.1
pycrypto: 2.6.1
pyasn1: 0.1.7
mock: 1.0.1
service-identity: 14.0.0
characteristic: 14.3.0
pyasn1-modules: 0.0.5
setuptools: 3.3

gzi2nwh4#1 2015-08-14_19:58:11.472290Z: want to subscribe, but no introducer yet
gzi2nwh4#3 2015-08-14_19:58:11.492492Z: init_web(webport=8421)
gzi2nwh4#4 2015-08-14_19:58:11.526420Z: Log opened.
gzi2nwh4#5 2015-08-14_19:58:11.526585Z: twistd 15.0.0 (/usr/bin/python 2.7.6) starting up.
gzi2nwh4#6 2015-08-14_19:58:11.526668Z: reactor class: twisted.internet.epollreactor.EPollReactor.
gzi2nwh4#7 2015-08-14_19:58:11.530040Z: Listener starting on 34227
gzi2nwh4#8 2015-08-14_19:58:11.530364Z: Starting factory <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl>
gzi2nwh4#9 2015-08-14_19:58:11.531043Z: NevowSite starting on 8421
gzi2nwh4#10 2015-08-14_19:58:11.531136Z: Starting factory <nevow.appserver.NevowSite instance at 0x7f72a48db2d8>
gzi2nwh4#11 2015-08-14_19:58:11.531440Z: Node.startService
gzi2nwh4#12 2015-08-14_19:58:11.531460Z: My pid: 18820
gzi2nwh4#13 2015-08-14_19:58:11.531965Z: Node._startService
gzi2nwh4#14 2015-08-14_19:58:11.533778Z: DatagramProtocol starting on 39227
gzi2nwh4#15 2015-08-14_19:58:11.533962Z: Starting protocol <twisted.internet.protocol.DatagramProtocol instance at 0x7f72a48ebd40>
gzi2nwh4#16 2015-08-14_19:58:11.538243Z: (UDP Port 39227 Closed)
gzi2nwh4#17 2015-08-14_19:58:11.538391Z: Stopping protocol <twisted.internet.protocol.DatagramProtocol instance at 0x7f72a48ebd40>
gzi2nwh4#18 2015-08-14_19:58:11.549350Z: Tub location set to 192.168.3.147:34227,127.0.0.1:34227
gzi2nwh4#19 2015-08-14_19:58:11.549741Z: client running
gzi2nwh4#20 2015-08-14_19:58:11.549961Z: TubConnector created from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 55goirgowl2cxnia6rtwxlp3teywzvaz
gzi2nwh4#21 2015-08-14_19:58:11.550014Z: connectTCP to ('54.211.175.5', 12345)
gzi2nwh4#22 2015-08-14_19:58:11.550091Z: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 55goirgo] at 0x7f72a488a5d0>
gzi2nwh4#23 2015-08-14_19:58:11.610218Z: Negotiation started
gzi2nwh4#34 2015-08-14_19:58:11.818192Z: dataReceived(isClient=True,phase=1,options={}): 'my-incarnation: 5bebf0bac3ac25e8\r\n'
gzi2nwh4#35 2015-08-14_19:58:11.818212Z: dataReceived(isClient=True,phase=1,options={}): 'my-tub-id: 55goirgowl2cxnia6rtwxlp3teywzvaz\r\n'
gzi2nwh4#36 2015-08-14_19:58:11.818231Z: dataReceived(isClient=True,phase=1,options={}): '\r\n'
gzi2nwh4#37 2015-08-14_19:58:11.818284Z: evaluateHello(isClient=True): offer={'my-tub-id': '55goirgowl2cxnia6rtwxlp3teywzvaz', 'my-incarnation': '5bebf0bac3ac25e8', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#38 2015-08-14_19:58:11.818396Z: iAmTheMaster: True
gzi2nwh4#39 2015-08-14_19:58:11.818447Z: Negotiation.sendDecision: {'current-connection': '37a4beb9e79a238a 1', 'initial-vocab-table-index': '1 bb33', 'banana-decision-version': '3'}
gzi2nwh4#40 2015-08-14_19:58:11.818521Z: Negotiate.switchToBanana(isClient=True)
gzi2nwh4#41 2015-08-14_19:58:11.818537Z: params: {'current-seqnum': 1, 'banana-decision-version': 3, 'current-slave-IR': '5bebf0bac3ac25e8', 'initial-vocab-table-index': 1}
gzi2nwh4#42 2015-08-14_19:58:11.819128Z: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 55goirgo] at 0x7f72a488a5d0> won
gzi2nwh4#43 2015-08-14_19:58:11.819154Z: connectorFinished (<foolscap.negotiate.TubConnector object at 0x7f72a488a510 from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 55goirgowl2cxnia6rtwxlp3teywzvaz>)
gzi2nwh4#44 2015-08-14_19:58:11.891927Z: connected to introducer, getting versions
gzi2nwh4#45 2015-08-14_19:58:11.957036Z: got introducer version: {'http://allmydata.org/tahoe/protocols/introducer/v1': {}, 'application-version': 'allmydata-tahoe/1.9.1.dev1'}
gzi2nwh4#46 2015-08-14_19:58:12.028614Z: received 1 announcements (v1)
gzi2nwh4#47 2015-08-14_19:58:12.028990Z: announcement for nickname 'lae-ffb2ee36-hwsl4vkmhmvqkx2dgie6ogn7sna2hn5x', service=storage: {u'app-versions': {}, u'oldest-supported': u'1.0.0', u'anonymous-storage-FURL': u'pb://6dwd2q4w2apsfh4boe2tvbgll2mtfnia@54.211.175.5:12346,ip-10-196-59-108.ec2.internal:12346/wysqf25nibj6nhvdi5eei65ly7lyrfvi', u'service-name': u'storage', u'version': 0, u'my-version': u'allmydata-tahoe/1.9.1.dev1', u'permutation-seed-base32': u'6dwd2q4w2apsfh4boe2tvbgll2mtfnia', u'nickname': u'lae-ffb2ee36-hwsl4vkmhmvqkx2dgie6ogn7sna2hn5x'}
gzi2nwh4#48 2015-08-14_19:58:12.029043Z: new announcement[storage]
gzi2nwh4#49 2015-08-14_19:58:12.030764Z: falling back to publish_v1
gzi2nwh4#50 2015-08-14_19:58:12.032054Z: TubConnector created from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 6dwd2q4w2apsfh4boe2tvbgll2mtfnia
gzi2nwh4#51 2015-08-14_19:58:12.032097Z: connectTCP to ('ip-10-196-59-108.ec2.internal', 12346)
gzi2nwh4#52 2015-08-14_19:58:12.032145Z: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af10>
gzi2nwh4#53 2015-08-14_19:58:12.032282Z: connectTCP to ('54.211.175.5', 12346)
gzi2nwh4#54 2015-08-14_19:58:12.032315Z: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af90>
gzi2nwh4#55 2015-08-14_19:58:12.092282Z: Negotiation started
gzi2nwh4#56 2015-08-14_19:58:12.092344Z: initClient: to target pb://6dwd2q4w2apsfh4boe2tvbgll2mtfnia
gzi2nwh4#57 2015-08-14_19:58:12.092410Z: sendPlaintextClient: GET for tubID 6dwd2q4w2apsfh4boe2tvbgll2mtfnia
gzi2nwh4#58 2015-08-14_19:58:12.092425Z: sendPlaintextClient: wantEncryption=True
gzi2nwh4#59 2015-08-14_19:58:12.101054Z: Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af10>
gzi2nwh4#60 2015-08-14_19:58:12.157423Z: 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'
gzi2nwh4#61 2015-08-14_19:58:12.157460Z: handlePLAINTEXTClient: header='HTTP/1.1 101 Switching Protocols
Upgrade: TLS/1.0, PB/1.0
Connection: Upgrade'
gzi2nwh4#62 2015-08-14_19:58:12.157480Z: startENCRYPTED(isClient=True)
gzi2nwh4#63 2015-08-14_19:58:12.157491Z: startTLS, client=True
gzi2nwh4#64 2015-08-14_19:58:12.161680Z: Negotiate.sendHello (isClient=True): {'my-incarnation': '37a4beb9e79a238a', 'last-connection': 'none 0', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#65 2015-08-14_19:58:12.283602Z: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n'
gzi2nwh4#66 2015-08-14_19:58:12.283643Z: dataReceived(isClient=True,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n'
gzi2nwh4#67 2015-08-14_19:58:12.283665Z: dataReceived(isClient=True,phase=1,options={}): 'my-incarnation: c01140ccf9e2c4ad\r\n'
gzi2nwh4#68 2015-08-14_19:58:12.283695Z: dataReceived(isClient=True,phase=1,options={}): 'my-tub-id: 6dwd2q4w2apsfh4boe2tvbgll2mtfnia\r\n'
gzi2nwh4#69 2015-08-14_19:58:12.283715Z: dataReceived(isClient=True,phase=1,options={}): '\r\n'
gzi2nwh4#70 2015-08-14_19:58:12.283761Z: evaluateHello(isClient=True): offer={'my-tub-id': '6dwd2q4w2apsfh4boe2tvbgll2mtfnia', 'my-incarnation': 'c01140ccf9e2c4ad', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#71 2015-08-14_19:58:12.283866Z: iAmTheMaster: True
gzi2nwh4#72 2015-08-14_19:58:12.283910Z: Negotiation.sendDecision: {'current-connection': '37a4beb9e79a238a 1', 'initial-vocab-table-index': '1 bb33', 'banana-decision-version': '3'}
gzi2nwh4#73 2015-08-14_19:58:12.283987Z: Negotiate.switchToBanana(isClient=True)
gzi2nwh4#74 2015-08-14_19:58:12.284001Z: params: {'current-seqnum': 1, 'banana-decision-version': 3, 'current-slave-IR': 'c01140ccf9e2c4ad', 'initial-vocab-table-index': 1}
gzi2nwh4#75 2015-08-14_19:58:12.284183Z: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af90> won
gzi2nwh4#76 2015-08-14_19:58:12.284209Z: connectorFinished (<foolscap.negotiate.TubConnector object at 0x7f72a404aed0 from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 6dwd2q4w2apsfh4boe2tvbgll2mtfnia>)
gzi2nwh4#77 2015-08-14_19:58:12.354376Z: got connection to 6dwd2q, getting versions
gzi2nwh4#78 2015-08-14_19:58:12.424392Z: 6dwd2q provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'fills-holes-with-zero-bytes': True, 'delete-mutable-shares-with-zero-length-writev': True, 'tolerates-immutable-read-overrun': True, 'has-immutable-readv': True, 'prevents-read-past-end-of-share-data': True, 'maximum-immutable-share-size': 18446744073709551616L}, 'application-version': 'allmydata-tahoe/1.9.1.dev1'}
gzi2nwh4#79 2015-08-14_19:58:42.316562Z: SharemapUpdater(ia2sk): starting (MODE_READ)
gzi2nwh4#80 2015-08-14_19:58:42.316662Z: sending query to [6dwd2q], readsize=4000
gzi2nwh4#81 2015-08-14_19:58:42.549164Z: got result from [6dwd2q], 0 shares
gzi2nwh4#82 2015-08-14_19:58:42.549253Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#83 2015-08-14_19:58:42.549273Z: all queries are retired, no extra servers: done
gzi2nwh4#84 2015-08-14_19:58:42.549299Z: servermap: 
gzi2nwh4#85 2015-08-14_19:58:42.549334Z: _got_results done
gzi2nwh4#86 2015-08-14_19:58:42.549360Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#87 2015-08-14_19:58:42.549372Z: but we're not running
gzi2nwh4#88 2015-08-14_19:58:42.550163Z: web: 127.0.0.1 GET /uri/[CENSORED]..?t=json 410 390
gzi2nwh4#89 2015-08-14_19:58:43.056637Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#90 2015-08-14_19:58:43.636827Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#91 2015-08-14_19:58:43.971431Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#92 2015-08-14_19:58:44.276341Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#93 2015-08-14_19:58:44.601836Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#94 2015-08-14_19:58:45.217647Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#95 2015-08-14_19:58:45.440088Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#96 2015-08-14_19:58:45.668971Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#97 2015-08-14_19:58:46.253720Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#98 2015-08-14_19:58:46.584793Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#99 2015-08-14_19:58:46.917931Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#100 2015-08-14_19:58:47.168231Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#101 2015-08-14_19:58:47.383204Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#102 2015-08-14_19:58:47.592803Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#103 2015-08-14_19:58:47.820724Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#104 2015-08-14_19:58:48.107146Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#105 2015-08-14_19:58:48.444724Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#106 2015-08-14_19:58:48.764935Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#107 2015-08-14_19:58:49.127958Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#108 2015-08-14_19:58:49.428231Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#109 2015-08-14_19:58:49.624255Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#110 2015-08-14_19:58:50.136504Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#111 2015-08-14_19:58:50.332420Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#112 2015-08-14_19:58:50.529079Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#113 2015-08-14_19:58:50.781128Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#114 2015-08-14_19:58:51.033473Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#115 2015-08-14_19:58:51.253299Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#116 2015-08-14_19:58:51.604588Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#117 2015-08-14_19:58:51.825428Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#118 2015-08-14_19:58:52.064764Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#119 2015-08-14_19:58:52.292366Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#120 2015-08-14_19:58:52.847523Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#121 2015-08-14_19:58:53.221430Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#122 2015-08-14_19:58:53.464679Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#123 2015-08-14_19:58:53.736816Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#124 2015-08-14_19:58:54.388962Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#125 2015-08-14_19:58:54.920962Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#126 2015-08-14_19:58:55.472666Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#127 2015-08-14_19:58:55.912923Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#128 2015-08-14_19:58:56.178184Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#129 2015-08-14_19:58:56.448842Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#130 2015-08-14_19:58:57.877926Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#131 2015-08-14_19:58:58.320641Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#132 2015-08-14_19:58:58.424290Z: CHKUploader starting
gzi2nwh4#133 2015-08-14_19:58:58.424344Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f5c7bd8>
gzi2nwh4#139 2015-08-14_19:58:58.428159Z: using storage index ozudu
gzi2nwh4#140 2015-08-14_19:58:58.428214Z: <Tahoe2ServerSelector for upload ozudu>(ozudu): starting
gzi2nwh4#141 2015-08-14_19:58:58.519728Z: <Tahoe2ServerSelector for upload ozudu>(ozudu): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#142 2015-08-14_19:58:58.519918Z: <Tahoe2ServerSelector for upload ozudu>(ozudu): server selection successful for <Tahoe2ServerSelector for upload ozudu>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#143 2015-08-14_19:58:58.519958Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#194 2015-08-14_19:58:59.529182Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98
gzi2nwh4#195 2015-08-14_19:58:59.581881Z: CHKUploader starting
gzi2nwh4#196 2015-08-14_19:58:59.581933Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f5ad560>
gzi2nwh4#202 2015-08-14_19:58:59.585299Z: using storage index untxg
gzi2nwh4#203 2015-08-14_19:58:59.585345Z: <Tahoe2ServerSelector for upload untxg>(untxg): starting
gzi2nwh4#204 2015-08-14_19:58:59.694564Z: <Tahoe2ServerSelector for upload untxg>(untxg): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#205 2015-08-14_19:58:59.694730Z: <Tahoe2ServerSelector for upload untxg>(untxg): server selection successful for <Tahoe2ServerSelector for upload untxg>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#206 2015-08-14_19:58:59.694770Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#248 2015-08-14_19:59:00.352339Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98
gzi2nwh4#249 2015-08-14_19:59:00.687411Z: CHKUploader starting
gzi2nwh4#250 2015-08-14_19:59:00.687453Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f4dfe18>
gzi2nwh4#256 2015-08-14_19:59:00.688905Z: using storage index gliua
gzi2nwh4#257 2015-08-14_19:59:00.688941Z: <Tahoe2ServerSelector for upload gliua>(gliua): starting
gzi2nwh4#258 2015-08-14_19:59:00.778964Z: <Tahoe2ServerSelector for upload gliua>(gliua): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#259 2015-08-14_19:59:00.779128Z: <Tahoe2ServerSelector for upload gliua>(gliua): server selection successful for <Tahoe2ServerSelector for upload gliua>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#260 2015-08-14_19:59:00.779165Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#285 2015-08-14_19:59:01.245378Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=mkdir-immutable 200 103
gzi2nwh4#286 2015-08-14_19:59:01.485085Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#287 2015-08-14_19:59:02.548619Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#288 2015-08-14_19:59:02.796467Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#289 2015-08-14_19:59:03.154285Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573
gzi2nwh4#290 2015-08-14_19:59:03.253215Z: CHKUploader starting
gzi2nwh4#291 2015-08-14_19:59:03.253254Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3f7b00>
gzi2nwh4#297 2015-08-14_19:59:03.255280Z: using storage index zkguy
gzi2nwh4#298 2015-08-14_19:59:03.255320Z: <Tahoe2ServerSelector for upload zkguy>(zkguy): starting
gzi2nwh4#299 2015-08-14_19:59:03.385140Z: <Tahoe2ServerSelector for upload zkguy>(zkguy): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#300 2015-08-14_19:59:03.385313Z: <Tahoe2ServerSelector for upload zkguy>(zkguy): server selection successful for <Tahoe2ServerSelector for upload zkguy>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#301 2015-08-14_19:59:03.385355Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#334 2015-08-14_19:59:04.041832Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98
gzi2nwh4#335 2015-08-14_19:59:04.093976Z: CHKUploader starting
gzi2nwh4#336 2015-08-14_19:59:04.094022Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3eb680>
gzi2nwh4#342 2015-08-14_19:59:04.129604Z: using storage index cqvu4
gzi2nwh4#343 2015-08-14_19:59:04.129662Z: <Tahoe2ServerSelector for upload cqvu4>(cqvu4): starting
gzi2nwh4#344 2015-08-14_19:59:04.235559Z: <Tahoe2ServerSelector for upload cqvu4>(cqvu4): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#345 2015-08-14_19:59:04.235738Z: <Tahoe2ServerSelector for upload cqvu4>(cqvu4): server selection successful for <Tahoe2ServerSelector for upload cqvu4>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#346 2015-08-14_19:59:04.235778Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#804 2015-08-14_19:59:13.883331Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 99
gzi2nwh4#805 2015-08-14_19:59:13.922194Z: CHKUploader starting
gzi2nwh4#806 2015-08-14_19:59:13.922239Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f38d5f0>
gzi2nwh4#812 2015-08-14_19:59:13.922965Z: using storage index uhre4
gzi2nwh4#813 2015-08-14_19:59:13.923003Z: <Tahoe2ServerSelector for upload uhre4>(uhre4): starting
gzi2nwh4#814 2015-08-14_19:59:14.111371Z: <Tahoe2ServerSelector for upload uhre4>(uhre4): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#815 2015-08-14_19:59:14.111540Z: <Tahoe2ServerSelector for upload uhre4>(uhre4): server selection successful for <Tahoe2ServerSelector for upload uhre4>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#816 2015-08-14_19:59:14.111581Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#834 2015-08-14_19:59:14.452094Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 97
gzi2nwh4#835 2015-08-14_19:59:14.551259Z: CHKUploader starting
gzi2nwh4#836 2015-08-14_19:59:14.551301Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f38d1b8>
gzi2nwh4#842 2015-08-14_19:59:14.597563Z: using storage index h2glt
gzi2nwh4#843 2015-08-14_19:59:14.597618Z: <Tahoe2ServerSelector for upload h2glt>(h2glt): starting
gzi2nwh4#844 2015-08-14_19:59:14.701208Z: <Tahoe2ServerSelector for upload h2glt>(h2glt): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#845 2015-08-14_19:59:14.701375Z: <Tahoe2ServerSelector for upload h2glt>(h2glt): server selection successful for <Tahoe2ServerSelector for upload h2glt>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#846 2015-08-14_19:59:14.701416Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#920 2015-08-14_19:59:15.678719Z: <Encoder for h2glt> uploaded 1048576 / 8519680 bytes (12%) of your file.
gzi2nwh4#929 2015-08-14_19:59:15.794502Z: <Encoder for h2glt> uploaded 1179648 / 8519680 bytes (13%) of your file.
gzi2nwh4#938 2015-08-14_19:59:15.909517Z: <Encoder for h2glt> uploaded 1310720 / 8519680 bytes (15%) of your file.
gzi2nwh4#947 2015-08-14_19:59:16.029367Z: <Encoder for h2glt> uploaded 1441792 / 8519680 bytes (16%) of your file.
gzi2nwh4#956 2015-08-14_19:59:16.147799Z: <Encoder for h2glt> uploaded 1572864 / 8519680 bytes (18%) of your file.
gzi2nwh4#965 2015-08-14_19:59:16.265305Z: <Encoder for h2glt> uploaded 1703936 / 8519680 bytes (20%) of your file.
gzi2nwh4#974 2015-08-14_19:59:16.382482Z: <Encoder for h2glt> uploaded 1835008 / 8519680 bytes (21%) of your file.
gzi2nwh4#983 2015-08-14_19:59:16.499439Z: <Encoder for h2glt> uploaded 1966080 / 8519680 bytes (23%) of your file.
gzi2nwh4#992 2015-08-14_19:59:16.618716Z: <Encoder for h2glt> uploaded 2097152 / 8519680 bytes (24%) of your file.
gzi2nwh4#1001 2015-08-14_19:59:16.737745Z: <Encoder for h2glt> uploaded 2228224 / 8519680 bytes (26%) of your file.
gzi2nwh4#1010 2015-08-14_19:59:16.857203Z: <Encoder for h2glt> uploaded 2359296 / 8519680 bytes (27%) of your file.
gzi2nwh4#1019 2015-08-14_19:59:16.978866Z: <Encoder for h2glt> uploaded 2490368 / 8519680 bytes (29%) of your file.
gzi2nwh4#1028 2015-08-14_19:59:17.098858Z: <Encoder for h2glt> uploaded 2621440 / 8519680 bytes (30%) of your file.
gzi2nwh4#1037 2015-08-14_19:59:17.214921Z: <Encoder for h2glt> uploaded 2752512 / 8519680 bytes (32%) of your file.
gzi2nwh4#1046 2015-08-14_19:59:17.332566Z: <Encoder for h2glt> uploaded 2883584 / 8519680 bytes (33%) of your file.
gzi2nwh4#1055 2015-08-14_19:59:17.452060Z: <Encoder for h2glt> uploaded 3014656 / 8519680 bytes (35%) of your file.
gzi2nwh4#1064 2015-08-14_19:59:17.569375Z: <Encoder for h2glt> uploaded 3145728 / 8519680 bytes (36%) of your file.
gzi2nwh4#1073 2015-08-14_19:59:17.686240Z: <Encoder for h2glt> uploaded 3276800 / 8519680 bytes (38%) of your file.
gzi2nwh4#1082 2015-08-14_19:59:17.843214Z: <Encoder for h2glt> uploaded 3407872 / 8519680 bytes (40%) of your file.
gzi2nwh4#1091 2015-08-14_19:59:17.960306Z: <Encoder for h2glt> uploaded 3538944 / 8519680 bytes (41%) of your file.
gzi2nwh4#1100 2015-08-14_19:59:18.080105Z: <Encoder for h2glt> uploaded 3670016 / 8519680 bytes (43%) of your file.
gzi2nwh4#1109 2015-08-14_19:59:18.198580Z: <Encoder for h2glt> uploaded 3801088 / 8519680 bytes (44%) of your file.
gzi2nwh4#1118 2015-08-14_19:59:18.314532Z: <Encoder for h2glt> uploaded 3932160 / 8519680 bytes (46%) of your file.
gzi2nwh4#1127 2015-08-14_19:59:18.434286Z: <Encoder for h2glt> uploaded 4063232 / 8519680 bytes (47%) of your file.
gzi2nwh4#1136 2015-08-14_19:59:18.549338Z: <Encoder for h2glt> uploaded 4194304 / 8519680 bytes (49%) of your file.
gzi2nwh4#1145 2015-08-14_19:59:18.669250Z: <Encoder for h2glt> uploaded 4325376 / 8519680 bytes (50%) of your file.
gzi2nwh4#1154 2015-08-14_19:59:18.790509Z: <Encoder for h2glt> uploaded 4456448 / 8519680 bytes (52%) of your file.
gzi2nwh4#1163 2015-08-14_19:59:18.910815Z: <Encoder for h2glt> uploaded 4587520 / 8519680 bytes (53%) of your file.
gzi2nwh4#1172 2015-08-14_19:59:19.026370Z: <Encoder for h2glt> uploaded 4718592 / 8519680 bytes (55%) of your file.
gzi2nwh4#1181 2015-08-14_19:59:19.224390Z: <Encoder for h2glt> uploaded 4849664 / 8519680 bytes (56%) of your file.
gzi2nwh4#1190 2015-08-14_19:59:19.385905Z: <Encoder for h2glt> uploaded 4980736 / 8519680 bytes (58%) of your file.
gzi2nwh4#1199 2015-08-14_19:59:19.502284Z: <Encoder for h2glt> uploaded 5111808 / 8519680 bytes (60%) of your file.
gzi2nwh4#1208 2015-08-14_19:59:19.618499Z: <Encoder for h2glt> uploaded 5242880 / 8519680 bytes (61%) of your file.
gzi2nwh4#1217 2015-08-14_19:59:19.782355Z: <Encoder for h2glt> uploaded 5373952 / 8519680 bytes (63%) of your file.
gzi2nwh4#1226 2015-08-14_19:59:19.898144Z: <Encoder for h2glt> uploaded 5505024 / 8519680 bytes (64%) of your file.
gzi2nwh4#1235 2015-08-14_19:59:20.017352Z: <Encoder for h2glt> uploaded 5636096 / 8519680 bytes (66%) of your file.
gzi2nwh4#1244 2015-08-14_19:59:20.138521Z: <Encoder for h2glt> uploaded 5767168 / 8519680 bytes (67%) of your file.
gzi2nwh4#1253 2015-08-14_19:59:20.271048Z: <Encoder for h2glt> uploaded 5898240 / 8519680 bytes (69%) of your file.
gzi2nwh4#1262 2015-08-14_19:59:20.390491Z: <Encoder for h2glt> uploaded 6029312 / 8519680 bytes (70%) of your file.
gzi2nwh4#1271 2015-08-14_19:59:20.510556Z: <Encoder for h2glt> uploaded 6160384 / 8519680 bytes (72%) of your file.
gzi2nwh4#1280 2015-08-14_19:59:20.626941Z: <Encoder for h2glt> uploaded 6291456 / 8519680 bytes (73%) of your file.
gzi2nwh4#1289 2015-08-14_19:59:20.750680Z: <Encoder for h2glt> uploaded 6422528 / 8519680 bytes (75%) of your file.
gzi2nwh4#1298 2015-08-14_19:59:20.869395Z: <Encoder for h2glt> uploaded 6553600 / 8519680 bytes (76%) of your file.
gzi2nwh4#1307 2015-08-14_19:59:20.986284Z: <Encoder for h2glt> uploaded 6684672 / 8519680 bytes (78%) of your file.
gzi2nwh4#1316 2015-08-14_19:59:21.111241Z: <Encoder for h2glt> uploaded 6815744 / 8519680 bytes (80%) of your file.
gzi2nwh4#1325 2015-08-14_19:59:21.230094Z: <Encoder for h2glt> uploaded 6946816 / 8519680 bytes (81%) of your file.
gzi2nwh4#1334 2015-08-14_19:59:21.350500Z: <Encoder for h2glt> uploaded 7077888 / 8519680 bytes (83%) of your file.
gzi2nwh4#1343 2015-08-14_19:59:21.478198Z: <Encoder for h2glt> uploaded 7208960 / 8519680 bytes (84%) of your file.
gzi2nwh4#1352 2015-08-14_19:59:21.610661Z: <Encoder for h2glt> uploaded 7340032 / 8519680 bytes (86%) of your file.
gzi2nwh4#1361 2015-08-14_19:59:21.726507Z: <Encoder for h2glt> uploaded 7471104 / 8519680 bytes (87%) of your file.
gzi2nwh4#1370 2015-08-14_19:59:21.846560Z: <Encoder for h2glt> uploaded 7602176 / 8519680 bytes (89%) of your file.
gzi2nwh4#1379 2015-08-14_19:59:21.962270Z: <Encoder for h2glt> uploaded 7733248 / 8519680 bytes (90%) of your file.
gzi2nwh4#1388 2015-08-14_19:59:22.086476Z: <Encoder for h2glt> uploaded 7864320 / 8519680 bytes (92%) of your file.
gzi2nwh4#1394 2015-08-14_19:59:22.090320Z: send_segment(60)
gzi2nwh4#1395 2015-08-14_19:59:22.090339Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1396 2015-08-14_19:59:22.206284Z: put_block done
gzi2nwh4#1397 2015-08-14_19:59:22.206389Z: <Encoder for h2glt> uploaded 7995392 / 8519680 bytes (93%) of your file.
gzi2nwh4#1398 2015-08-14_19:59:22.206727Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1399 2015-08-14_19:59:22.207600Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1400 2015-08-14_19:59:22.208456Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1401 2015-08-14_19:59:22.208765Z: closed hash [61]: 131072B
gzi2nwh4#1402 2015-08-14_19:59:22.208837Z: plaintext leaf hash [61] is 2lyukfjv6kubtn2v3vzdzazozozouphrb5ekhkx2zobv7j7k2wwq
gzi2nwh4#1403 2015-08-14_19:59:22.210309Z: send_segment(61)
gzi2nwh4#1404 2015-08-14_19:59:22.210329Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1405 2015-08-14_19:59:22.326303Z: put_block done
gzi2nwh4#1406 2015-08-14_19:59:22.326402Z: <Encoder for h2glt> uploaded 8126464 / 8519680 bytes (95%) of your file.
gzi2nwh4#1407 2015-08-14_19:59:22.326710Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1408 2015-08-14_19:59:22.327492Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1409 2015-08-14_19:59:22.328264Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1410 2015-08-14_19:59:22.328566Z: closed hash [62]: 131072B
gzi2nwh4#1411 2015-08-14_19:59:22.328625Z: plaintext leaf hash [62] is czub42tbenefcwlbg6vwch4dmukdamawsno5qs7n73lnaspp4zja
gzi2nwh4#1412 2015-08-14_19:59:22.330092Z: send_segment(62)
gzi2nwh4#1413 2015-08-14_19:59:22.330111Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1414 2015-08-14_19:59:22.449037Z: put_block done
gzi2nwh4#1415 2015-08-14_19:59:22.449143Z: <Encoder for h2glt> uploaded 8257536 / 8519680 bytes (96%) of your file.
gzi2nwh4#1416 2015-08-14_19:59:22.449469Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1417 2015-08-14_19:59:22.450352Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1418 2015-08-14_19:59:22.451214Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1419 2015-08-14_19:59:22.451550Z: closed hash [63]: 131072B
gzi2nwh4#1420 2015-08-14_19:59:22.451620Z: plaintext leaf hash [63] is 3pcr4jbg2spryvhdaaavig3lgokdaf4p5qgxvuta57eubd3uxpvq
gzi2nwh4#1421 2015-08-14_19:59:22.453263Z: send_segment(63)
gzi2nwh4#1422 2015-08-14_19:59:22.453285Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1423 2015-08-14_19:59:22.563496Z: put_block done
gzi2nwh4#1424 2015-08-14_19:59:22.563594Z: <Encoder for h2glt> uploaded 8388608 / 8519680 bytes (98%) of your file.
gzi2nwh4#1425 2015-08-14_19:59:22.563935Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1426 2015-08-14_19:59:22.564817Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1427 2015-08-14_19:59:22.565680Z:  read_encrypted handling 28371B-sized chunk
gzi2nwh4#1428 2015-08-14_19:59:22.567620Z: send_segment(64)
gzi2nwh4#1429 2015-08-14_19:59:22.567641Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1430 2015-08-14_19:59:22.687463Z: put_block done
gzi2nwh4#1431 2015-08-14_19:59:22.687562Z: <Encoder for h2glt> uploaded 8519680 / 8519680 bytes (100%) of your file.
gzi2nwh4#1432 2015-08-14_19:59:22.687740Z: sending crypttext hash tree
gzi2nwh4#1433 2015-08-14_19:59:22.690135Z: sending block hash trees
gzi2nwh4#1434 2015-08-14_19:59:22.692389Z: sending all share hash trees
gzi2nwh4#1435 2015-08-14_19:59:22.693001Z: sending uri_extension
gzi2nwh4#1436 2015-08-14_19:59:22.693263Z: uri_extension_data is {'num_segments': 65, 'crypttext_hash': 'gmwy4la2px3szrcudxrj6ryb4da7nikcl4skfzwlwzhl6pr7n2vq', 'tail_codec_params': '130771-1-1', 'share_root_hash': 'kfrkjzsfco5snmea7iww4vmjjse5ayjn7ducf76lqli5ob47334q', 'crypttext_root_hash': 'd5cv6otfclluryntwi5dz6dzflksmokimc5goto7ndkz2kqnoagq', 'codec_params': '131072-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 131072, 'size': 8519379}
gzi2nwh4#1437 2015-08-14_19:59:22.693882Z: closing shareholders
gzi2nwh4#1438 2015-08-14_19:59:24.783435Z: upload done
gzi2nwh4#1439 2015-08-14_19:59:24.784450Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 99
gzi2nwh4#1440 2015-08-14_19:59:24.844047Z: CHKUploader starting
gzi2nwh4#1441 2015-08-14_19:59:24.844089Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3f7b48>
gzi2nwh4#1442 2015-08-14_19:59:24.844121Z: creating Encoder <Encoder for unknown storage index>
gzi2nwh4#1443 2015-08-14_19:59:24.844162Z: file size: 645271
gzi2nwh4#1444 2015-08-14_19:59:24.844221Z: my encoding parameters: (1, 1, 1, 131072)
gzi2nwh4#1445 2015-08-14_19:59:24.844249Z: got encoding parameters: 1/1/1 131072
gzi2nwh4#1446 2015-08-14_19:59:24.844259Z: now setting up codec
gzi2nwh4#1447 2015-08-14_19:59:24.847820Z: using storage index h2fei
gzi2nwh4#1448 2015-08-14_19:59:24.847861Z: <Tahoe2ServerSelector for upload h2fei>(h2fei): starting
gzi2nwh4#1449 2015-08-14_19:59:24.965356Z: <Tahoe2ServerSelector for upload h2fei>(h2fei): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#1450 2015-08-14_19:59:24.965518Z: <Tahoe2ServerSelector for upload h2fei>(h2fei): server selection successful for <Tahoe2ServerSelector for upload h2fei>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#1451 2015-08-14_19:59:24.965558Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#1452 2015-08-14_19:59:24.965639Z: <Encoder for h2fei> starting
gzi2nwh4#1453 2015-08-14_19:59:24.965790Z: starting shareholders
gzi2nwh4#1454 2015-08-14_19:59:24.966643Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1455 2015-08-14_19:59:24.967494Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1456 2015-08-14_19:59:24.968343Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1457 2015-08-14_19:59:24.968646Z: closed hash [0]: 131072B
gzi2nwh4#1458 2015-08-14_19:59:24.968714Z: plaintext leaf hash [0] is r7ftjqxuhfb4fneu4qlpvkzzwy4ixhhih7bjhmz7wfvnsktsmuaq
gzi2nwh4#1459 2015-08-14_19:59:24.970175Z: send_segment(0)
gzi2nwh4#1460 2015-08-14_19:59:24.970192Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1461 2015-08-14_19:59:25.308685Z: put_block done
gzi2nwh4#1462 2015-08-14_19:59:25.308789Z: <Encoder for h2fei> uploaded 131072 / 655360 bytes (20%) of your file.
gzi2nwh4#1463 2015-08-14_19:59:25.309115Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1464 2015-08-14_19:59:25.310000Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1465 2015-08-14_19:59:25.310864Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1466 2015-08-14_19:59:25.311203Z: closed hash [1]: 131072B
gzi2nwh4#1467 2015-08-14_19:59:25.311269Z: plaintext leaf hash [1] is jg4gnvxhmhmec5nrguntnrs75s6iwb6eablsnp3gasfxmbq7mlyq
gzi2nwh4#1468 2015-08-14_19:59:25.312910Z: send_segment(1)
gzi2nwh4#1469 2015-08-14_19:59:25.312931Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1470 2015-08-14_19:59:25.427310Z: put_block done
gzi2nwh4#1471 2015-08-14_19:59:25.427409Z: <Encoder for h2fei> uploaded 262144 / 655360 bytes (40%) of your file.
gzi2nwh4#1472 2015-08-14_19:59:25.427725Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1473 2015-08-14_19:59:25.428509Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1474 2015-08-14_19:59:25.429282Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1475 2015-08-14_19:59:25.429584Z: closed hash [2]: 131072B
gzi2nwh4#1476 2015-08-14_19:59:25.429656Z: plaintext leaf hash [2] is it3khulmol2jwmhk5tsob2opd6h2wlsnotlpqmv4awjkqzghdgaq
gzi2nwh4#1477 2015-08-14_19:59:25.431195Z: send_segment(2)
gzi2nwh4#1478 2015-08-14_19:59:25.431214Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1479 2015-08-14_19:59:25.546415Z: put_block done
gzi2nwh4#1480 2015-08-14_19:59:25.546516Z: <Encoder for h2fei> uploaded 393216 / 655360 bytes (60%) of your file.
gzi2nwh4#1481 2015-08-14_19:59:25.546835Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1482 2015-08-14_19:59:25.547648Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1483 2015-08-14_19:59:25.548450Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1484 2015-08-14_19:59:25.548768Z: closed hash [3]: 131072B
gzi2nwh4#1485 2015-08-14_19:59:25.548831Z: plaintext leaf hash [3] is ulrhwo7d5xup47d5n4kxcjk7znz2422lick7wyhdzodvbyl5wegq
gzi2nwh4#1486 2015-08-14_19:59:25.550348Z: send_segment(3)
gzi2nwh4#1487 2015-08-14_19:59:25.550368Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1488 2015-08-14_19:59:25.667967Z: put_block done
gzi2nwh4#1489 2015-08-14_19:59:25.668067Z: <Encoder for h2fei> uploaded 524288 / 655360 bytes (80%) of your file.
gzi2nwh4#1490 2015-08-14_19:59:25.668375Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1491 2015-08-14_19:59:25.669229Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1492 2015-08-14_19:59:25.670139Z:  read_encrypted handling 18583B-sized chunk
gzi2nwh4#1493 2015-08-14_19:59:25.671714Z: send_segment(4)
gzi2nwh4#1494 2015-08-14_19:59:25.671735Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1495 2015-08-14_19:59:25.779546Z: put_block done
gzi2nwh4#1496 2015-08-14_19:59:25.779648Z: <Encoder for h2fei> uploaded 655360 / 655360 bytes (100%) of your file.
gzi2nwh4#1497 2015-08-14_19:59:25.779830Z: sending crypttext hash tree
gzi2nwh4#1498 2015-08-14_19:59:25.780663Z: sending block hash trees
gzi2nwh4#1499 2015-08-14_19:59:25.781375Z: sending all share hash trees
gzi2nwh4#1500 2015-08-14_19:59:25.781971Z: sending uri_extension
gzi2nwh4#1501 2015-08-14_19:59:25.782198Z: uri_extension_data is {'num_segments': 5, 'crypttext_hash': '5lyr42cwkbrfnhfxdskyxamwj3eiqohhj4r62v72iavwfl6bim7q', 'tail_codec_params': '120983-1-1', 'share_root_hash': '3cijmogyhq4hpfzvdwq65w3cygb6r2pkuoeskqxewgmzykhhdyoa', 'crypttext_root_hash': 'lq43s5eolutc44ip227kags4lejvjdtb3ipihofzeet22yjr26na', 'codec_params': '131072-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 131072, 'size': 645271}
gzi2nwh4#1502 2015-08-14_19:59:25.782805Z: closing shareholders
gzi2nwh4#1503 2015-08-14_19:59:25.981746Z: upload done
gzi2nwh4#1504 2015-08-14_19:59:25.982604Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98
gzi2nwh4#1505 2015-08-14_19:59:26.051620Z: CHKUploader starting
gzi2nwh4#1506 2015-08-14_19:59:26.051686Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3f7cb0>
gzi2nwh4#1507 2015-08-14_19:59:26.051733Z: creating Encoder <Encoder for unknown storage index>
gzi2nwh4#1508 2015-08-14_19:59:26.051785Z: file size: 1293042
gzi2nwh4#1509 2015-08-14_19:59:26.051846Z: my encoding parameters: (1, 1, 1, 131072)
gzi2nwh4#1510 2015-08-14_19:59:26.051875Z: got encoding parameters: 1/1/1 131072
gzi2nwh4#1511 2015-08-14_19:59:26.051884Z: now setting up codec
gzi2nwh4#1512 2015-08-14_19:59:26.058721Z: using storage index kdzug
gzi2nwh4#1513 2015-08-14_19:59:26.058763Z: <Tahoe2ServerSelector for upload kdzug>(kdzug): starting
gzi2nwh4#1514 2015-08-14_19:59:26.246807Z: <Tahoe2ServerSelector for upload kdzug>(kdzug): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#1515 2015-08-14_19:59:26.246968Z: <Tahoe2ServerSelector for upload kdzug>(kdzug): server selection successful for <Tahoe2ServerSelector for upload kdzug>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#1516 2015-08-14_19:59:26.247009Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#1517 2015-08-14_19:59:26.247090Z: <Encoder for kdzug> starting
gzi2nwh4#1518 2015-08-14_19:59:26.247250Z: starting shareholders
gzi2nwh4#1519 2015-08-14_19:59:26.248117Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1520 2015-08-14_19:59:26.248967Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1521 2015-08-14_19:59:26.249741Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1522 2015-08-14_19:59:26.250041Z: closed hash [0]: 131072B
gzi2nwh4#1523 2015-08-14_19:59:26.250101Z: plaintext leaf hash [0] is fqw56ywniyusqmed72ey7kgnobrjlyejn57xp2secvfnfjfghz4q
gzi2nwh4#1524 2015-08-14_19:59:26.251599Z: send_segment(0)
gzi2nwh4#1525 2015-08-14_19:59:26.251616Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1526 2015-08-14_19:59:26.414078Z: put_block done
gzi2nwh4#1527 2015-08-14_19:59:26.414185Z: <Encoder for kdzug> uploaded 131072 / 1310720 bytes (10%) of your file.
gzi2nwh4#1528 2015-08-14_19:59:26.414513Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1529 2015-08-14_19:59:26.415400Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1530 2015-08-14_19:59:26.416264Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1531 2015-08-14_19:59:26.416599Z: closed hash [1]: 131072B
gzi2nwh4#1532 2015-08-14_19:59:26.416665Z: plaintext leaf hash [1] is gggvrn774b7pxzy6w2wdjsppabtt42zn4qtaulombzn5wehh3nxq
gzi2nwh4#1533 2015-08-14_19:59:26.418361Z: send_segment(1)
gzi2nwh4#1534 2015-08-14_19:59:26.418405Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1535 2015-08-14_19:59:26.530791Z: put_block done
gzi2nwh4#1536 2015-08-14_19:59:26.530891Z: <Encoder for kdzug> uploaded 262144 / 1310720 bytes (20%) of your file.
gzi2nwh4#1537 2015-08-14_19:59:26.531213Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1538 2015-08-14_19:59:26.532004Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1539 2015-08-14_19:59:26.532776Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1540 2015-08-14_19:59:26.533077Z: closed hash [2]: 131072B
gzi2nwh4#1541 2015-08-14_19:59:26.533137Z: plaintext leaf hash [2] is ut4va3py6lgrcewt7l3b3g2iuwce3rom4lxjesk7jaheqsalq3iq
gzi2nwh4#1542 2015-08-14_19:59:26.534667Z: send_segment(2)
gzi2nwh4#1543 2015-08-14_19:59:26.534692Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1544 2015-08-14_19:59:26.654973Z: put_block done
gzi2nwh4#1545 2015-08-14_19:59:26.655165Z: <Encoder for kdzug> uploaded 393216 / 1310720 bytes (30%) of your file.
gzi2nwh4#1546 2015-08-14_19:59:26.655664Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1547 2015-08-14_19:59:26.656562Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1548 2015-08-14_19:59:26.657428Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1549 2015-08-14_19:59:26.657772Z: closed hash [3]: 131072B
gzi2nwh4#1550 2015-08-14_19:59:26.657840Z: plaintext leaf hash [3] is y2j4cun22h6f44qbr6vo34325dnivyttobjc54oo2ftqeajpug2a
gzi2nwh4#1551 2015-08-14_19:59:26.659567Z: send_segment(3)
gzi2nwh4#1552 2015-08-14_19:59:26.659600Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1553 2015-08-14_19:59:26.772586Z: put_block done
gzi2nwh4#1554 2015-08-14_19:59:26.772699Z: <Encoder for kdzug> uploaded 524288 / 1310720 bytes (40%) of your file.
gzi2nwh4#1555 2015-08-14_19:59:26.773021Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1556 2015-08-14_19:59:26.773861Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1557 2015-08-14_19:59:26.774627Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1558 2015-08-14_19:59:26.774935Z: closed hash [4]: 131072B
gzi2nwh4#1559 2015-08-14_19:59:26.774995Z: plaintext leaf hash [4] is j37tleornitie7zuq4wbd25wozis2mteo7wvxa66gkqjuufhrpxq
gzi2nwh4#1560 2015-08-14_19:59:26.776460Z: send_segment(4)
gzi2nwh4#1561 2015-08-14_19:59:26.776493Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1562 2015-08-14_19:59:26.891527Z: put_block done
gzi2nwh4#1563 2015-08-14_19:59:26.891633Z: <Encoder for kdzug> uploaded 655360 / 1310720 bytes (50%) of your file.
gzi2nwh4#1564 2015-08-14_19:59:26.891956Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1565 2015-08-14_19:59:26.892801Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1566 2015-08-14_19:59:26.893565Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1567 2015-08-14_19:59:26.893872Z: closed hash [5]: 131072B
gzi2nwh4#1568 2015-08-14_19:59:26.893933Z: plaintext leaf hash [5] is g74222vueyevzq45oppxrgvpycyq5tzherhck65jfojmnivql3lq
gzi2nwh4#1569 2015-08-14_19:59:26.895395Z: send_segment(5)
gzi2nwh4#1570 2015-08-14_19:59:26.895414Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1571 2015-08-14_19:59:27.015477Z: put_block done
gzi2nwh4#1572 2015-08-14_19:59:27.015578Z: <Encoder for kdzug> uploaded 786432 / 1310720 bytes (60%) of your file.
gzi2nwh4#1573 2015-08-14_19:59:27.015923Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1574 2015-08-14_19:59:27.016716Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1575 2015-08-14_19:59:27.017482Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1576 2015-08-14_19:59:27.017822Z: closed hash [6]: 131072B
gzi2nwh4#1577 2015-08-14_19:59:27.017883Z: plaintext leaf hash [6] is j67wjp5nmguwpoku4vbxllz6ipoegfsa2l6vxglief4tq7up2f7a
gzi2nwh4#1578 2015-08-14_19:59:27.019345Z: send_segment(6)
gzi2nwh4#1579 2015-08-14_19:59:27.019365Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1580 2015-08-14_19:59:27.138680Z: put_block done
gzi2nwh4#1581 2015-08-14_19:59:27.138788Z: <Encoder for kdzug> uploaded 917504 / 1310720 bytes (70%) of your file.
gzi2nwh4#1582 2015-08-14_19:59:27.139115Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1583 2015-08-14_19:59:27.140001Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1584 2015-08-14_19:59:27.140866Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1585 2015-08-14_19:59:27.141202Z: closed hash [7]: 131072B
gzi2nwh4#1586 2015-08-14_19:59:27.141268Z: plaintext leaf hash [7] is 3n5l5cenud735pcov35u2cghcbu5atzcdudqrbobdi5nhv6x4uvq
gzi2nwh4#1587 2015-08-14_19:59:27.142949Z: send_segment(7)
gzi2nwh4#1588 2015-08-14_19:59:27.142975Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1589 2015-08-14_19:59:27.254379Z: put_block done
gzi2nwh4#1590 2015-08-14_19:59:27.254482Z: <Encoder for kdzug> uploaded 1048576 / 1310720 bytes (80%) of your file.
gzi2nwh4#1591 2015-08-14_19:59:27.254805Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1592 2015-08-14_19:59:27.255641Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1593 2015-08-14_19:59:27.256414Z:  read_encrypted handling 28672B-sized chunk
gzi2nwh4#1594 2015-08-14_19:59:27.256722Z: closed hash [8]: 131072B
gzi2nwh4#1595 2015-08-14_19:59:27.256783Z: plaintext leaf hash [8] is hag2mwv7ks5mdcni2lfbhmd2ugcucl4u6ysio2wbabci7qanvv3q
gzi2nwh4#1596 2015-08-14_19:59:27.258246Z: send_segment(8)
gzi2nwh4#1597 2015-08-14_19:59:27.258265Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1598 2015-08-14_19:59:27.371455Z: put_block done
gzi2nwh4#1599 2015-08-14_19:59:27.371556Z: <Encoder for kdzug> uploaded 1179648 / 1310720 bytes (90%) of your file.
gzi2nwh4#1600 2015-08-14_19:59:27.371865Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1601 2015-08-14_19:59:27.372648Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1602 2015-08-14_19:59:27.373418Z:  read_encrypted handling 10994B-sized chunk
gzi2nwh4#1603 2015-08-14_19:59:27.374762Z: send_segment(9)
gzi2nwh4#1604 2015-08-14_19:59:27.374779Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1605 2015-08-14_19:59:27.476623Z: put_block done
gzi2nwh4#1606 2015-08-14_19:59:27.476736Z: <Encoder for kdzug> uploaded 1310720 / 1310720 bytes (100%) of your file.
gzi2nwh4#1607 2015-08-14_19:59:27.476905Z: sending crypttext hash tree
gzi2nwh4#1608 2015-08-14_19:59:27.477833Z: sending block hash trees
gzi2nwh4#1609 2015-08-14_19:59:27.478635Z: sending all share hash trees
gzi2nwh4#1610 2015-08-14_19:59:27.479229Z: sending uri_extension
gzi2nwh4#1611 2015-08-14_19:59:27.479458Z: uri_extension_data is {'num_segments': 10, 'crypttext_hash': '7jp5eritd7yohuuntlvsorediqxii67cpxnp5rgcjyphl2tor2xa', 'tail_codec_params': '113394-1-1', 'share_root_hash': 'oy73gwu3pjkuxjp6jcgzyd35fffev54qwbjf5mihjh5xeomff5zq', 'crypttext_root_hash': 'pkff6tgiamojh3nh47eslu6qikov7xmzyujov33xw7jj6zcpgdhq', 'codec_params': '131072-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 131072, 'size': 1293042}
gzi2nwh4#1612 2015-08-14_19:59:27.480066Z: closing shareholders
gzi2nwh4#1613 2015-08-14_19:59:27.758158Z: upload done
gzi2nwh4#1614 2015-08-14_19:59:27.758922Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 99
gzi2nwh4#1615 2015-08-14_19:59:27.864428Z: CHKUploader starting
gzi2nwh4#1616 2015-08-14_19:59:27.864470Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f5ade18>
gzi2nwh4#1617 2015-08-14_19:59:27.864504Z: creating Encoder <Encoder for unknown storage index>
gzi2nwh4#1618 2015-08-14_19:59:27.864543Z: file size: 76972
gzi2nwh4#1619 2015-08-14_19:59:27.864598Z: my encoding parameters: (1, 1, 1, 76972)
gzi2nwh4#1620 2015-08-14_19:59:27.864626Z: got encoding parameters: 1/1/1 76972
gzi2nwh4#1621 2015-08-14_19:59:27.864636Z: now setting up codec
gzi2nwh4#1622 2015-08-14_19:59:27.865212Z: using storage index bc7xg
gzi2nwh4#1623 2015-08-14_19:59:27.865250Z: <Tahoe2ServerSelector for upload bc7xg>(bc7xg): starting
gzi2nwh4#1624 2015-08-14_19:59:27.957665Z: <Tahoe2ServerSelector for upload bc7xg>(bc7xg): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#1625 2015-08-14_19:59:27.957936Z: <Tahoe2ServerSelector for upload bc7xg>(bc7xg): server selection successful for <Tahoe2ServerSelector for upload bc7xg>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#1626 2015-08-14_19:59:27.957999Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#1627 2015-08-14_19:59:27.958127Z: <Encoder for bc7xg> starting
gzi2nwh4#1628 2015-08-14_19:59:27.958339Z: starting shareholders
gzi2nwh4#1629 2015-08-14_19:59:27.959780Z:  read_encrypted handling 51200B-sized chunk
gzi2nwh4#1630 2015-08-14_19:59:27.961236Z:  read_encrypted handling 25772B-sized chunk
gzi2nwh4#1631 2015-08-14_19:59:27.961695Z: closed hash [0]: 76972B
gzi2nwh4#1632 2015-08-14_19:59:27.961792Z: plaintext leaf hash [0] is c6ljqqpowsorcw5pp274ql2qylufdbgklugzijc2mkdegbm4ljva
gzi2nwh4#1633 2015-08-14_19:59:27.963311Z: send_segment(0)
gzi2nwh4#1634 2015-08-14_19:59:27.963339Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1635 2015-08-14_19:59:28.123022Z: put_block done
gzi2nwh4#1636 2015-08-14_19:59:28.123121Z: <Encoder for bc7xg> uploaded 76972 / 76972 bytes (100%) of your file.
gzi2nwh4#1637 2015-08-14_19:59:28.123291Z: sending crypttext hash tree
gzi2nwh4#1638 2015-08-14_19:59:28.124001Z: sending block hash trees
gzi2nwh4#1639 2015-08-14_19:59:28.124607Z: sending all share hash trees
gzi2nwh4#1640 2015-08-14_19:59:28.125221Z: sending uri_extension
gzi2nwh4#1641 2015-08-14_19:59:28.125514Z: uri_extension_data is {'num_segments': 1, 'crypttext_hash': '5hy3qxzx74zev6qxqicf7f6uw6x3ksxt3iaud5edwcwotranf4qa', 'tail_codec_params': '76972-1-1', 'share_root_hash': 'tz5yuzytreox6f7mk4ddzg3yykubsbvgr5pvdjlxvxlpumxrrlbq', 'crypttext_root_hash': 'uci6o3xbgvspgz4veoq4vaypbrzuhot5ush2dj564yvm6daxzpgq', 'codec_params': '76972-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 76972, 'size': 76972}
gzi2nwh4#1642 2015-08-14_19:59:28.126198Z: closing shareholders
gzi2nwh4#1643 2015-08-14_19:59:28.397949Z: upload done
gzi2nwh4#1644 2015-08-14_19:59:28.399173Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=mkdir-immutable 200 102
gzi2nwh4#1645 2015-08-14_19:59:28.450803Z: CHKUploader starting
gzi2nwh4#1646 2015-08-14_19:59:28.450845Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f465cf8>
gzi2nwh4#1647 2015-08-14_19:59:28.450881Z: creating Encoder <Encoder for unknown storage index>
gzi2nwh4#1648 2015-08-14_19:59:28.450922Z: file size: 4151
gzi2nwh4#1649 2015-08-14_19:59:28.451014Z: my encoding parameters: (1, 1, 1, 4151)
gzi2nwh4#1650 2015-08-14_19:59:28.451045Z: got encoding parameters: 1/1/1 4151
gzi2nwh4#1651 2015-08-14_19:59:28.451055Z: now setting up codec
gzi2nwh4#1652 2015-08-14_19:59:28.451257Z: using storage index wianb
gzi2nwh4#1653 2015-08-14_19:59:28.451292Z: <Tahoe2ServerSelector for upload wianb>(wianb): starting
gzi2nwh4#1654 2015-08-14_19:59:28.565584Z: <Tahoe2ServerSelector for upload wianb>(wianb): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,)
gzi2nwh4#1655 2015-08-14_19:59:28.565759Z: <Tahoe2ServerSelector for upload wianb>(wianb): server selection successful for <Tahoe2ServerSelector for upload wianb>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: 
gzi2nwh4#1656 2015-08-14_19:59:28.565798Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {}
gzi2nwh4#1657 2015-08-14_19:59:28.565881Z: <Encoder for wianb> starting
gzi2nwh4#1658 2015-08-14_19:59:28.566013Z: starting shareholders
gzi2nwh4#1659 2015-08-14_19:59:28.566854Z:  read_encrypted handling 4151B-sized chunk
gzi2nwh4#1660 2015-08-14_19:59:28.566930Z: closed hash [0]: 4151B
gzi2nwh4#1661 2015-08-14_19:59:28.567003Z: plaintext leaf hash [0] is neldvpuig7btee3fcbc3ss7jjyb5wa3pfrlciq2e5t7wqk6vvdpq
gzi2nwh4#1662 2015-08-14_19:59:28.567161Z: send_segment(0)
gzi2nwh4#1663 2015-08-14_19:59:28.567192Z: put_block to <WriteBucketProxy for node 6dwd2q>
gzi2nwh4#1664 2015-08-14_19:59:28.567816Z: put_block done
gzi2nwh4#1665 2015-08-14_19:59:28.567939Z: <Encoder for wianb> uploaded 4151 / 4151 bytes (100%) of your file.
gzi2nwh4#1666 2015-08-14_19:59:28.568094Z: sending crypttext hash tree
gzi2nwh4#1667 2015-08-14_19:59:28.568767Z: sending block hash trees
gzi2nwh4#1668 2015-08-14_19:59:28.569386Z: sending all share hash trees
gzi2nwh4#1669 2015-08-14_19:59:28.570008Z: sending uri_extension
gzi2nwh4#1670 2015-08-14_19:59:28.570246Z: uri_extension_data is {'num_segments': 1, 'crypttext_hash': '3govd5hhcfybzqin3wgsdxhooxxrsvsqn55oeoppmon2robtm5ea', 'tail_codec_params': '4151-1-1', 'share_root_hash': 'ppkka3e6sz77go2ojmznwkzlgv3lclukpfufhtvgkdc3dlt6q2xq', 'crypttext_root_hash': '4x3p46hanu3bcxll6n2qseuiyd4ca4nnnjfnxeda4vrsvvli6izq', 'codec_params': '4151-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 4151, 'size': 4151}
gzi2nwh4#1671 2015-08-14_19:59:28.570888Z: closing shareholders
gzi2nwh4#1672 2015-08-14_19:59:28.772181Z: upload done
gzi2nwh4#1673 2015-08-14_19:59:28.773339Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=mkdir-immutable 200 101
gzi2nwh4#1674 2015-08-14_19:59:28.798450Z: SharemapUpdater(ia2sk): starting (MODE_READ)
gzi2nwh4#1675 2015-08-14_19:59:28.798536Z: sending query to [6dwd2q], readsize=4000
gzi2nwh4#1676 2015-08-14_19:59:28.942096Z: got result from [6dwd2q], 0 shares
gzi2nwh4#1677 2015-08-14_19:59:28.942174Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#1678 2015-08-14_19:59:28.942193Z: all queries are retired, no extra servers: done
gzi2nwh4#1679 2015-08-14_19:59:28.942217Z: servermap: 
gzi2nwh4#1680 2015-08-14_19:59:28.942250Z: _got_results done
gzi2nwh4#1681 2015-08-14_19:59:28.942276Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#1682 2015-08-14_19:59:28.942290Z: but we're not running
gzi2nwh4#1683 2015-08-14_19:59:28.942770Z: web: 127.0.0.1 PUT /uri/[CENSORED]..?t=uri 410 390
gzi2nwh4#1684 2015-08-14_20:54:51.429384Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '127.0.0.1', 57428)
gzi2nwh4#1685 2015-08-14_20:54:51.429415Z: Negotiation started
gzi2nwh4#1686 2015-08-14_20:54:51.429467Z: initServer
gzi2nwh4#1687 2015-08-14_20:54:51.429657Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '192.168.3.147', 50238)
gzi2nwh4#1688 2015-08-14_20:54:51.429689Z: Negotiation started
gzi2nwh4#1689 2015-08-14_20:54:51.429734Z: initServer
gzi2nwh4#1690 2015-08-14_20:54:51.430172Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 127.0.0.1\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n'
gzi2nwh4#1691 2015-08-14_20:54:51.430216Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl'
gzi2nwh4#1692 2015-08-14_20:54:51.430234Z: handlePLAINTEXTServer: wantEncrypted=True
gzi2nwh4#1693 2015-08-14_20:54:51.430280Z: startENCRYPTED(isClient=False)
gzi2nwh4#1694 2015-08-14_20:54:51.430294Z: startTLS, client=False
gzi2nwh4#1695 2015-08-14_20:54:51.434693Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1696 2015-08-14_20:54:51.434923Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 192.168.3.147\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n'
gzi2nwh4#1697 2015-08-14_20:54:51.434962Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl'
gzi2nwh4#1698 2015-08-14_20:54:51.434983Z: handlePLAINTEXTServer: wantEncrypted=True
gzi2nwh4#1699 2015-08-14_20:54:51.435045Z: startENCRYPTED(isClient=False)
gzi2nwh4#1700 2015-08-14_20:54:51.435065Z: startTLS, client=False
gzi2nwh4#1701 2015-08-14_20:54:51.440927Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1702 2015-08-14_20:54:51.455921Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n'
gzi2nwh4#1703 2015-08-14_20:54:51.455974Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n'
gzi2nwh4#1704 2015-08-14_20:54:51.455998Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n'
gzi2nwh4#1705 2015-08-14_20:54:51.456021Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: c96bed8982be4e79\r\n'
gzi2nwh4#1706 2015-08-14_20:54:51.456042Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx\r\n'
gzi2nwh4#1707 2015-08-14_20:54:51.456063Z: dataReceived(isClient=False,phase=1,options={}): '\r\n'
gzi2nwh4#1708 2015-08-14_20:54:51.456113Z: evaluateHello(isClient=False): offer={'my-tub-id': 'xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx', 'last-connection': 'none 0', 'my-incarnation': 'c96bed8982be4e79', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1709 2015-08-14_20:54:51.456211Z: iAmTheMaster: False
gzi2nwh4#1710 2015-08-14_20:54:51.456238Z: dataReceived(isClient=False,phase=2,options={}): 'banana-decision-version: 3\r\n'
gzi2nwh4#1711 2015-08-14_20:54:51.456259Z: dataReceived(isClient=False,phase=2,options={}): 'current-connection: c96bed8982be4e79 1\r\n'
gzi2nwh4#1712 2015-08-14_20:54:51.456280Z: dataReceived(isClient=False,phase=2,options={}): 'initial-vocab-table-index: 1 bb33\r\n'
gzi2nwh4#1713 2015-08-14_20:54:51.456300Z: dataReceived(isClient=False,phase=2,options={}): '\r\n'
gzi2nwh4#1714 2015-08-14_20:54:51.456315Z: handleDECIDING(isClient=False): banana-decision-version: 3
current-connection: c96bed8982be4e79 1
initial-vocab-table-index: 1 bb33
gzi2nwh4#1715 2015-08-14_20:54:51.456338Z: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'c96bed8982be4e79 1'}
gzi2nwh4#1716 2015-08-14_20:54:51.456383Z: Negotiate.switchToBanana(isClient=False)
gzi2nwh4#1717 2015-08-14_20:54:51.456398Z: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
gzi2nwh4#1718 2015-08-14_20:54:51.458066Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n'
gzi2nwh4#1719 2015-08-14_20:54:51.458110Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n'
gzi2nwh4#1720 2015-08-14_20:54:51.458148Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n'
gzi2nwh4#1721 2015-08-14_20:54:51.458187Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: c96bed8982be4e79\r\n'
gzi2nwh4#1722 2015-08-14_20:54:51.458224Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx\r\n'
gzi2nwh4#1723 2015-08-14_20:54:51.458261Z: dataReceived(isClient=False,phase=1,options={}): '\r\n'
gzi2nwh4#1724 2015-08-14_20:54:51.458328Z: evaluateHello(isClient=False): offer={'my-tub-id': 'xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx', 'last-connection': 'none 0', 'my-incarnation': 'c96bed8982be4e79', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1725 2015-08-14_20:54:51.458461Z: iAmTheMaster: False
gzi2nwh4#1726 2015-08-14_20:54:51.458832Z: negotiationFailed: ConnectionDone
gzi2nwh4#1727 2015-08-14_20:54:51.488218Z: Unhandled error in Deferred:
gzi2nwh4#1728 2015-08-14_20:54:51.488549Z: Unhandled Error
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send
    d.callback(None)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback
    self._startRunCallbacks(result)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks
    self._runCallbacks()
  File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
--- <exception caught here> ---
  File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 215, in produce
    slicer = self.newSlicerFor(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor
    return topSlicer.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject
    raise Violation("cannot serialize %s (%s)" % (obj, name))
foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",)

 FAILURE:
 [CopiedFailure instance: Traceback from remote host -- Traceback (most recent call last):
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send
     d.callback(None)
   File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback
     self._startRunCallbacks(result)
   File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks
     self._runCallbacks()
   File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks
     current.result = callback(current.result, *args, **kw)
 --- <excepti
 
 -- TRACEBACK ELIDED --
 
 banana.py", line 215, in produce
     slicer = self.newSlicerFor(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor
     return topSlicer.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject
     raise Violation("cannot serialize %s (%s)" % (obj, name))
 foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",)
 ]
gzi2nwh4#1729 2015-08-14_20:55:11.780106Z: connection to xfqd lost
gzi2nwh4#1730 2015-08-14_20:55:28.525037Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '127.0.0.1', 57434)
gzi2nwh4#1731 2015-08-14_20:55:28.525060Z: Negotiation started
gzi2nwh4#1732 2015-08-14_20:55:28.525093Z: initServer
gzi2nwh4#1733 2015-08-14_20:55:28.525222Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '192.168.3.147', 50244)
gzi2nwh4#1734 2015-08-14_20:55:28.525233Z: Negotiation started
gzi2nwh4#1735 2015-08-14_20:55:28.525255Z: initServer
gzi2nwh4#1736 2015-08-14_20:55:28.525576Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 127.0.0.1\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n'
gzi2nwh4#1737 2015-08-14_20:55:28.525629Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl'
gzi2nwh4#1738 2015-08-14_20:55:28.525643Z: handlePLAINTEXTServer: wantEncrypted=True
gzi2nwh4#1739 2015-08-14_20:55:28.525701Z: startENCRYPTED(isClient=False)
gzi2nwh4#1740 2015-08-14_20:55:28.525712Z: startTLS, client=False
gzi2nwh4#1741 2015-08-14_20:55:28.530385Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1742 2015-08-14_20:55:28.530601Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 192.168.3.147\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n'
gzi2nwh4#1743 2015-08-14_20:55:28.530628Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl'
gzi2nwh4#1744 2015-08-14_20:55:28.530642Z: handlePLAINTEXTServer: wantEncrypted=True
gzi2nwh4#1745 2015-08-14_20:55:28.530689Z: startENCRYPTED(isClient=False)
gzi2nwh4#1746 2015-08-14_20:55:28.530699Z: startTLS, client=False
gzi2nwh4#1747 2015-08-14_20:55:28.533575Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1748 2015-08-14_20:55:28.546900Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n'
gzi2nwh4#1749 2015-08-14_20:55:28.546947Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n'
gzi2nwh4#1750 2015-08-14_20:55:28.546967Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n'
gzi2nwh4#1751 2015-08-14_20:55:28.546984Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: 1962200e72784097\r\n'
gzi2nwh4#1752 2015-08-14_20:55:28.547002Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: wbvby75xnn5qw7n6shgkenpahnp7qhyt\r\n'
gzi2nwh4#1753 2015-08-14_20:55:28.547019Z: dataReceived(isClient=False,phase=1,options={}): '\r\n'
gzi2nwh4#1754 2015-08-14_20:55:28.547063Z: evaluateHello(isClient=False): offer={'my-tub-id': 'wbvby75xnn5qw7n6shgkenpahnp7qhyt', 'last-connection': 'none 0', 'my-incarnation': '1962200e72784097', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1755 2015-08-14_20:55:28.547152Z: iAmTheMaster: False
gzi2nwh4#1756 2015-08-14_20:55:28.547173Z: dataReceived(isClient=False,phase=2,options={}): 'banana-decision-version: 3\r\n'
gzi2nwh4#1757 2015-08-14_20:55:28.547192Z: dataReceived(isClient=False,phase=2,options={}): 'current-connection: 1962200e72784097 1\r\n'
gzi2nwh4#1758 2015-08-14_20:55:28.547209Z: dataReceived(isClient=False,phase=2,options={}): 'initial-vocab-table-index: 1 bb33\r\n'
gzi2nwh4#1759 2015-08-14_20:55:28.547225Z: dataReceived(isClient=False,phase=2,options={}): '\r\n'
gzi2nwh4#1760 2015-08-14_20:55:28.547239Z: handleDECIDING(isClient=False): banana-decision-version: 3
current-connection: 1962200e72784097 1
initial-vocab-table-index: 1 bb33
gzi2nwh4#1761 2015-08-14_20:55:28.547259Z: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '1962200e72784097 1'}
gzi2nwh4#1762 2015-08-14_20:55:28.547297Z: Negotiate.switchToBanana(isClient=False)
gzi2nwh4#1763 2015-08-14_20:55:28.547307Z: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1}
gzi2nwh4#1764 2015-08-14_20:55:28.548657Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n'
gzi2nwh4#1765 2015-08-14_20:55:28.548692Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n'
gzi2nwh4#1766 2015-08-14_20:55:28.548715Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n'
gzi2nwh4#1767 2015-08-14_20:55:28.548734Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: 1962200e72784097\r\n'
gzi2nwh4#1768 2015-08-14_20:55:28.548753Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: wbvby75xnn5qw7n6shgkenpahnp7qhyt\r\n'
gzi2nwh4#1769 2015-08-14_20:55:28.548772Z: dataReceived(isClient=False,phase=1,options={}): '\r\n'
gzi2nwh4#1770 2015-08-14_20:55:28.548808Z: evaluateHello(isClient=False): offer={'my-tub-id': 'wbvby75xnn5qw7n6shgkenpahnp7qhyt', 'last-connection': 'none 0', 'my-incarnation': '1962200e72784097', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'}
gzi2nwh4#1771 2015-08-14_20:55:28.548885Z: iAmTheMaster: False
gzi2nwh4#1772 2015-08-14_20:55:28.549109Z: negotiationFailed: ConnectionDone
gzi2nwh4#1773 2015-08-14_20:55:28.572906Z: Unhandled error in Deferred:
gzi2nwh4#1774 2015-08-14_20:55:28.573527Z: Unhandled Error
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send
    d.callback(None)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback
    self._startRunCallbacks(result)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks
    self._runCallbacks()
  File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
--- <exception caught here> ---
  File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 215, in produce
    slicer = self.newSlicerFor(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor
    return topSlicer.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
    return self.parent.slicerForObject(obj)
  File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject
    raise Violation("cannot serialize %s (%s)" % (obj, name))
foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",)

 FAILURE:
 [CopiedFailure instance: Traceback from remote host -- Traceback (most recent call last):
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send
     d.callback(None)
   File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback
     self._startRunCallbacks(result)
   File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks
     self._runCallbacks()
   File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks
     current.result = callback(current.result, *args, **kw)
 --- <excepti
 
 -- TRACEBACK ELIDED --
 
 banana.py", line 215, in produce
     slicer = self.newSlicerFor(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor
     return topSlicer.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject
     return self.parent.slicerForObject(obj)
   File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject
     raise Violation("cannot serialize %s (%s)" % (obj, name))
 foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",)
 ]
I just uploaded [flog-catchup.flog](/tahoe-lafs/trac-2024-07-25/attachments/000078ac-eaf7-c689-4787-1239123fb2fc), which resulted from using this command: `time tahoe debug flogtool tail --verbose --catch-up --save-to=flog-catchup.flog --timestamps=utc ~/.tahoe/private/logport.furl`. If you look at that file with `flogtool dump --timestamps=utc`, it outputs this: ``` Application versions (embedded in logfile): Nevow: 0.11.1 OpenSSL: 1.0.1f Twisted: 15.0.0 allmydata-tahoe: 1.10.1 characteristic: 14.3.0 foolscap: 0.8.0 mock: 1.0.1 platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF pyOpenSSL: 0.13 pyasn1: 0.1.7 pyasn1-modules: 0.0.5 pycrypto: 2.6.1 pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958 python: 2.7.6 service-identity: 14.0.0 setuptools: 3.3 simplejson: 3.3.1 twisted: 15.0.0 zfec: 1.4.24 zope.interface: unknown PID: 18820 gzi2nwh4#0 2015-08-14_19:58:11.468818Z: Node constructed. allmydata-tahoe: 1.10.1 [master: 2875a9ffc415cd665026419001f2311b4efd44e1] foolscap: 0.8.0 pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958 zfec: 1.4.24 Twisted: 15.0.0 Nevow: 0.11.1 zope.interface: unknown python: 2.7.6 platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF pyOpenSSL: 0.13 OpenSSL: 1.0.1f [6 Jan 2014] simplejson: 3.3.1 pycrypto: 2.6.1 pyasn1: 0.1.7 mock: 1.0.1 service-identity: 14.0.0 characteristic: 14.3.0 pyasn1-modules: 0.0.5 setuptools: 3.3 gzi2nwh4#1 2015-08-14_19:58:11.472290Z: want to subscribe, but no introducer yet gzi2nwh4#3 2015-08-14_19:58:11.492492Z: init_web(webport=8421) gzi2nwh4#4 2015-08-14_19:58:11.526420Z: Log opened. gzi2nwh4#5 2015-08-14_19:58:11.526585Z: twistd 15.0.0 (/usr/bin/python 2.7.6) starting up. gzi2nwh4#6 2015-08-14_19:58:11.526668Z: reactor class: twisted.internet.epollreactor.EPollReactor. gzi2nwh4#7 2015-08-14_19:58:11.530040Z: Listener starting on 34227 gzi2nwh4#8 2015-08-14_19:58:11.530364Z: Starting factory <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> gzi2nwh4#9 2015-08-14_19:58:11.531043Z: NevowSite starting on 8421 gzi2nwh4#10 2015-08-14_19:58:11.531136Z: Starting factory <nevow.appserver.NevowSite instance at 0x7f72a48db2d8> gzi2nwh4#11 2015-08-14_19:58:11.531440Z: Node.startService gzi2nwh4#12 2015-08-14_19:58:11.531460Z: My pid: 18820 gzi2nwh4#13 2015-08-14_19:58:11.531965Z: Node._startService gzi2nwh4#14 2015-08-14_19:58:11.533778Z: DatagramProtocol starting on 39227 gzi2nwh4#15 2015-08-14_19:58:11.533962Z: Starting protocol <twisted.internet.protocol.DatagramProtocol instance at 0x7f72a48ebd40> gzi2nwh4#16 2015-08-14_19:58:11.538243Z: (UDP Port 39227 Closed) gzi2nwh4#17 2015-08-14_19:58:11.538391Z: Stopping protocol <twisted.internet.protocol.DatagramProtocol instance at 0x7f72a48ebd40> gzi2nwh4#18 2015-08-14_19:58:11.549350Z: Tub location set to 192.168.3.147:34227,127.0.0.1:34227 gzi2nwh4#19 2015-08-14_19:58:11.549741Z: client running gzi2nwh4#20 2015-08-14_19:58:11.549961Z: TubConnector created from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 55goirgowl2cxnia6rtwxlp3teywzvaz gzi2nwh4#21 2015-08-14_19:58:11.550014Z: connectTCP to ('54.211.175.5', 12345) gzi2nwh4#22 2015-08-14_19:58:11.550091Z: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 55goirgo] at 0x7f72a488a5d0> gzi2nwh4#23 2015-08-14_19:58:11.610218Z: Negotiation started gzi2nwh4#34 2015-08-14_19:58:11.818192Z: dataReceived(isClient=True,phase=1,options={}): 'my-incarnation: 5bebf0bac3ac25e8\r\n' gzi2nwh4#35 2015-08-14_19:58:11.818212Z: dataReceived(isClient=True,phase=1,options={}): 'my-tub-id: 55goirgowl2cxnia6rtwxlp3teywzvaz\r\n' gzi2nwh4#36 2015-08-14_19:58:11.818231Z: dataReceived(isClient=True,phase=1,options={}): '\r\n' gzi2nwh4#37 2015-08-14_19:58:11.818284Z: evaluateHello(isClient=True): offer={'my-tub-id': '55goirgowl2cxnia6rtwxlp3teywzvaz', 'my-incarnation': '5bebf0bac3ac25e8', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#38 2015-08-14_19:58:11.818396Z: iAmTheMaster: True gzi2nwh4#39 2015-08-14_19:58:11.818447Z: Negotiation.sendDecision: {'current-connection': '37a4beb9e79a238a 1', 'initial-vocab-table-index': '1 bb33', 'banana-decision-version': '3'} gzi2nwh4#40 2015-08-14_19:58:11.818521Z: Negotiate.switchToBanana(isClient=True) gzi2nwh4#41 2015-08-14_19:58:11.818537Z: params: {'current-seqnum': 1, 'banana-decision-version': 3, 'current-slave-IR': '5bebf0bac3ac25e8', 'initial-vocab-table-index': 1} gzi2nwh4#42 2015-08-14_19:58:11.819128Z: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 55goirgo] at 0x7f72a488a5d0> won gzi2nwh4#43 2015-08-14_19:58:11.819154Z: connectorFinished (<foolscap.negotiate.TubConnector object at 0x7f72a488a510 from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 55goirgowl2cxnia6rtwxlp3teywzvaz>) gzi2nwh4#44 2015-08-14_19:58:11.891927Z: connected to introducer, getting versions gzi2nwh4#45 2015-08-14_19:58:11.957036Z: got introducer version: {'http://allmydata.org/tahoe/protocols/introducer/v1': {}, 'application-version': 'allmydata-tahoe/1.9.1.dev1'} gzi2nwh4#46 2015-08-14_19:58:12.028614Z: received 1 announcements (v1) gzi2nwh4#47 2015-08-14_19:58:12.028990Z: announcement for nickname 'lae-ffb2ee36-hwsl4vkmhmvqkx2dgie6ogn7sna2hn5x', service=storage: {u'app-versions': {}, u'oldest-supported': u'1.0.0', u'anonymous-storage-FURL': u'pb://6dwd2q4w2apsfh4boe2tvbgll2mtfnia@54.211.175.5:12346,ip-10-196-59-108.ec2.internal:12346/wysqf25nibj6nhvdi5eei65ly7lyrfvi', u'service-name': u'storage', u'version': 0, u'my-version': u'allmydata-tahoe/1.9.1.dev1', u'permutation-seed-base32': u'6dwd2q4w2apsfh4boe2tvbgll2mtfnia', u'nickname': u'lae-ffb2ee36-hwsl4vkmhmvqkx2dgie6ogn7sna2hn5x'} gzi2nwh4#48 2015-08-14_19:58:12.029043Z: new announcement[storage] gzi2nwh4#49 2015-08-14_19:58:12.030764Z: falling back to publish_v1 gzi2nwh4#50 2015-08-14_19:58:12.032054Z: TubConnector created from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 6dwd2q4w2apsfh4boe2tvbgll2mtfnia gzi2nwh4#51 2015-08-14_19:58:12.032097Z: connectTCP to ('ip-10-196-59-108.ec2.internal', 12346) gzi2nwh4#52 2015-08-14_19:58:12.032145Z: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af10> gzi2nwh4#53 2015-08-14_19:58:12.032282Z: connectTCP to ('54.211.175.5', 12346) gzi2nwh4#54 2015-08-14_19:58:12.032315Z: Starting factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af90> gzi2nwh4#55 2015-08-14_19:58:12.092282Z: Negotiation started gzi2nwh4#56 2015-08-14_19:58:12.092344Z: initClient: to target pb://6dwd2q4w2apsfh4boe2tvbgll2mtfnia gzi2nwh4#57 2015-08-14_19:58:12.092410Z: sendPlaintextClient: GET for tubID 6dwd2q4w2apsfh4boe2tvbgll2mtfnia gzi2nwh4#58 2015-08-14_19:58:12.092425Z: sendPlaintextClient: wantEncryption=True gzi2nwh4#59 2015-08-14_19:58:12.101054Z: Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af10> gzi2nwh4#60 2015-08-14_19:58:12.157423Z: 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' gzi2nwh4#61 2015-08-14_19:58:12.157460Z: handlePLAINTEXTClient: header='HTTP/1.1 101 Switching Protocols Upgrade: TLS/1.0, PB/1.0 Connection: Upgrade' gzi2nwh4#62 2015-08-14_19:58:12.157480Z: startENCRYPTED(isClient=True) gzi2nwh4#63 2015-08-14_19:58:12.157491Z: startTLS, client=True gzi2nwh4#64 2015-08-14_19:58:12.161680Z: Negotiate.sendHello (isClient=True): {'my-incarnation': '37a4beb9e79a238a', 'last-connection': 'none 0', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#65 2015-08-14_19:58:12.283602Z: dataReceived(isClient=True,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n' gzi2nwh4#66 2015-08-14_19:58:12.283643Z: dataReceived(isClient=True,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n' gzi2nwh4#67 2015-08-14_19:58:12.283665Z: dataReceived(isClient=True,phase=1,options={}): 'my-incarnation: c01140ccf9e2c4ad\r\n' gzi2nwh4#68 2015-08-14_19:58:12.283695Z: dataReceived(isClient=True,phase=1,options={}): 'my-tub-id: 6dwd2q4w2apsfh4boe2tvbgll2mtfnia\r\n' gzi2nwh4#69 2015-08-14_19:58:12.283715Z: dataReceived(isClient=True,phase=1,options={}): '\r\n' gzi2nwh4#70 2015-08-14_19:58:12.283761Z: evaluateHello(isClient=True): offer={'my-tub-id': '6dwd2q4w2apsfh4boe2tvbgll2mtfnia', 'my-incarnation': 'c01140ccf9e2c4ad', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#71 2015-08-14_19:58:12.283866Z: iAmTheMaster: True gzi2nwh4#72 2015-08-14_19:58:12.283910Z: Negotiation.sendDecision: {'current-connection': '37a4beb9e79a238a 1', 'initial-vocab-table-index': '1 bb33', 'banana-decision-version': '3'} gzi2nwh4#73 2015-08-14_19:58:12.283987Z: Negotiate.switchToBanana(isClient=True) gzi2nwh4#74 2015-08-14_19:58:12.284001Z: params: {'current-seqnum': 1, 'banana-decision-version': 3, 'current-slave-IR': 'c01140ccf9e2c4ad', 'initial-vocab-table-index': 1} gzi2nwh4#75 2015-08-14_19:58:12.284183Z: negotiationComplete, <foolscap.negotiate.TubConnectorClientFactory object [from gzi2nwh4] [to 6dwd2q4w] at 0x7f72a404af90> won gzi2nwh4#76 2015-08-14_19:58:12.284209Z: connectorFinished (<foolscap.negotiate.TubConnector object at 0x7f72a404aed0 from gzi2nwh4akud7r3ldeznjmxlumzf5rbl to 6dwd2q4w2apsfh4boe2tvbgll2mtfnia>) gzi2nwh4#77 2015-08-14_19:58:12.354376Z: got connection to 6dwd2q, getting versions gzi2nwh4#78 2015-08-14_19:58:12.424392Z: 6dwd2q provided version info {'http://allmydata.org/tahoe/protocols/storage/v1': {'fills-holes-with-zero-bytes': True, 'delete-mutable-shares-with-zero-length-writev': True, 'tolerates-immutable-read-overrun': True, 'has-immutable-readv': True, 'prevents-read-past-end-of-share-data': True, 'maximum-immutable-share-size': 18446744073709551616L}, 'application-version': 'allmydata-tahoe/1.9.1.dev1'} gzi2nwh4#79 2015-08-14_19:58:42.316562Z: SharemapUpdater(ia2sk): starting (MODE_READ) gzi2nwh4#80 2015-08-14_19:58:42.316662Z: sending query to [6dwd2q], readsize=4000 gzi2nwh4#81 2015-08-14_19:58:42.549164Z: got result from [6dwd2q], 0 shares gzi2nwh4#82 2015-08-14_19:58:42.549253Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#83 2015-08-14_19:58:42.549273Z: all queries are retired, no extra servers: done gzi2nwh4#84 2015-08-14_19:58:42.549299Z: servermap: gzi2nwh4#85 2015-08-14_19:58:42.549334Z: _got_results done gzi2nwh4#86 2015-08-14_19:58:42.549360Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#87 2015-08-14_19:58:42.549372Z: but we're not running gzi2nwh4#88 2015-08-14_19:58:42.550163Z: web: 127.0.0.1 GET /uri/[CENSORED]..?t=json 410 390 gzi2nwh4#89 2015-08-14_19:58:43.056637Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#90 2015-08-14_19:58:43.636827Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#91 2015-08-14_19:58:43.971431Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#92 2015-08-14_19:58:44.276341Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#93 2015-08-14_19:58:44.601836Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#94 2015-08-14_19:58:45.217647Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#95 2015-08-14_19:58:45.440088Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#96 2015-08-14_19:58:45.668971Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#97 2015-08-14_19:58:46.253720Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#98 2015-08-14_19:58:46.584793Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#99 2015-08-14_19:58:46.917931Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#100 2015-08-14_19:58:47.168231Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#101 2015-08-14_19:58:47.383204Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#102 2015-08-14_19:58:47.592803Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#103 2015-08-14_19:58:47.820724Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#104 2015-08-14_19:58:48.107146Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#105 2015-08-14_19:58:48.444724Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#106 2015-08-14_19:58:48.764935Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#107 2015-08-14_19:58:49.127958Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#108 2015-08-14_19:58:49.428231Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#109 2015-08-14_19:58:49.624255Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#110 2015-08-14_19:58:50.136504Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#111 2015-08-14_19:58:50.332420Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#112 2015-08-14_19:58:50.529079Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#113 2015-08-14_19:58:50.781128Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#114 2015-08-14_19:58:51.033473Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#115 2015-08-14_19:58:51.253299Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#116 2015-08-14_19:58:51.604588Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#117 2015-08-14_19:58:51.825428Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#118 2015-08-14_19:58:52.064764Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#119 2015-08-14_19:58:52.292366Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#120 2015-08-14_19:58:52.847523Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#121 2015-08-14_19:58:53.221430Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#122 2015-08-14_19:58:53.464679Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#123 2015-08-14_19:58:53.736816Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#124 2015-08-14_19:58:54.388962Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#125 2015-08-14_19:58:54.920962Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#126 2015-08-14_19:58:55.472666Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#127 2015-08-14_19:58:55.912923Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#128 2015-08-14_19:58:56.178184Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#129 2015-08-14_19:58:56.448842Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#130 2015-08-14_19:58:57.877926Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#131 2015-08-14_19:58:58.320641Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#132 2015-08-14_19:58:58.424290Z: CHKUploader starting gzi2nwh4#133 2015-08-14_19:58:58.424344Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f5c7bd8> gzi2nwh4#139 2015-08-14_19:58:58.428159Z: using storage index ozudu gzi2nwh4#140 2015-08-14_19:58:58.428214Z: <Tahoe2ServerSelector for upload ozudu>(ozudu): starting gzi2nwh4#141 2015-08-14_19:58:58.519728Z: <Tahoe2ServerSelector for upload ozudu>(ozudu): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#142 2015-08-14_19:58:58.519918Z: <Tahoe2ServerSelector for upload ozudu>(ozudu): server selection successful for <Tahoe2ServerSelector for upload ozudu>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#143 2015-08-14_19:58:58.519958Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#194 2015-08-14_19:58:59.529182Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98 gzi2nwh4#195 2015-08-14_19:58:59.581881Z: CHKUploader starting gzi2nwh4#196 2015-08-14_19:58:59.581933Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f5ad560> gzi2nwh4#202 2015-08-14_19:58:59.585299Z: using storage index untxg gzi2nwh4#203 2015-08-14_19:58:59.585345Z: <Tahoe2ServerSelector for upload untxg>(untxg): starting gzi2nwh4#204 2015-08-14_19:58:59.694564Z: <Tahoe2ServerSelector for upload untxg>(untxg): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#205 2015-08-14_19:58:59.694730Z: <Tahoe2ServerSelector for upload untxg>(untxg): server selection successful for <Tahoe2ServerSelector for upload untxg>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#206 2015-08-14_19:58:59.694770Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#248 2015-08-14_19:59:00.352339Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98 gzi2nwh4#249 2015-08-14_19:59:00.687411Z: CHKUploader starting gzi2nwh4#250 2015-08-14_19:59:00.687453Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f4dfe18> gzi2nwh4#256 2015-08-14_19:59:00.688905Z: using storage index gliua gzi2nwh4#257 2015-08-14_19:59:00.688941Z: <Tahoe2ServerSelector for upload gliua>(gliua): starting gzi2nwh4#258 2015-08-14_19:59:00.778964Z: <Tahoe2ServerSelector for upload gliua>(gliua): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#259 2015-08-14_19:59:00.779128Z: <Tahoe2ServerSelector for upload gliua>(gliua): server selection successful for <Tahoe2ServerSelector for upload gliua>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#260 2015-08-14_19:59:00.779165Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#285 2015-08-14_19:59:01.245378Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=mkdir-immutable 200 103 gzi2nwh4#286 2015-08-14_19:59:01.485085Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#287 2015-08-14_19:59:02.548619Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#288 2015-08-14_19:59:02.796467Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#289 2015-08-14_19:59:03.154285Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=check&output=JSON 200 573 gzi2nwh4#290 2015-08-14_19:59:03.253215Z: CHKUploader starting gzi2nwh4#291 2015-08-14_19:59:03.253254Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3f7b00> gzi2nwh4#297 2015-08-14_19:59:03.255280Z: using storage index zkguy gzi2nwh4#298 2015-08-14_19:59:03.255320Z: <Tahoe2ServerSelector for upload zkguy>(zkguy): starting gzi2nwh4#299 2015-08-14_19:59:03.385140Z: <Tahoe2ServerSelector for upload zkguy>(zkguy): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#300 2015-08-14_19:59:03.385313Z: <Tahoe2ServerSelector for upload zkguy>(zkguy): server selection successful for <Tahoe2ServerSelector for upload zkguy>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#301 2015-08-14_19:59:03.385355Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#334 2015-08-14_19:59:04.041832Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98 gzi2nwh4#335 2015-08-14_19:59:04.093976Z: CHKUploader starting gzi2nwh4#336 2015-08-14_19:59:04.094022Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3eb680> gzi2nwh4#342 2015-08-14_19:59:04.129604Z: using storage index cqvu4 gzi2nwh4#343 2015-08-14_19:59:04.129662Z: <Tahoe2ServerSelector for upload cqvu4>(cqvu4): starting gzi2nwh4#344 2015-08-14_19:59:04.235559Z: <Tahoe2ServerSelector for upload cqvu4>(cqvu4): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#345 2015-08-14_19:59:04.235738Z: <Tahoe2ServerSelector for upload cqvu4>(cqvu4): server selection successful for <Tahoe2ServerSelector for upload cqvu4>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#346 2015-08-14_19:59:04.235778Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#804 2015-08-14_19:59:13.883331Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 99 gzi2nwh4#805 2015-08-14_19:59:13.922194Z: CHKUploader starting gzi2nwh4#806 2015-08-14_19:59:13.922239Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f38d5f0> gzi2nwh4#812 2015-08-14_19:59:13.922965Z: using storage index uhre4 gzi2nwh4#813 2015-08-14_19:59:13.923003Z: <Tahoe2ServerSelector for upload uhre4>(uhre4): starting gzi2nwh4#814 2015-08-14_19:59:14.111371Z: <Tahoe2ServerSelector for upload uhre4>(uhre4): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#815 2015-08-14_19:59:14.111540Z: <Tahoe2ServerSelector for upload uhre4>(uhre4): server selection successful for <Tahoe2ServerSelector for upload uhre4>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#816 2015-08-14_19:59:14.111581Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#834 2015-08-14_19:59:14.452094Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 97 gzi2nwh4#835 2015-08-14_19:59:14.551259Z: CHKUploader starting gzi2nwh4#836 2015-08-14_19:59:14.551301Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f38d1b8> gzi2nwh4#842 2015-08-14_19:59:14.597563Z: using storage index h2glt gzi2nwh4#843 2015-08-14_19:59:14.597618Z: <Tahoe2ServerSelector for upload h2glt>(h2glt): starting gzi2nwh4#844 2015-08-14_19:59:14.701208Z: <Tahoe2ServerSelector for upload h2glt>(h2glt): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#845 2015-08-14_19:59:14.701375Z: <Tahoe2ServerSelector for upload h2glt>(h2glt): server selection successful for <Tahoe2ServerSelector for upload h2glt>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#846 2015-08-14_19:59:14.701416Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#920 2015-08-14_19:59:15.678719Z: <Encoder for h2glt> uploaded 1048576 / 8519680 bytes (12%) of your file. gzi2nwh4#929 2015-08-14_19:59:15.794502Z: <Encoder for h2glt> uploaded 1179648 / 8519680 bytes (13%) of your file. gzi2nwh4#938 2015-08-14_19:59:15.909517Z: <Encoder for h2glt> uploaded 1310720 / 8519680 bytes (15%) of your file. gzi2nwh4#947 2015-08-14_19:59:16.029367Z: <Encoder for h2glt> uploaded 1441792 / 8519680 bytes (16%) of your file. gzi2nwh4#956 2015-08-14_19:59:16.147799Z: <Encoder for h2glt> uploaded 1572864 / 8519680 bytes (18%) of your file. gzi2nwh4#965 2015-08-14_19:59:16.265305Z: <Encoder for h2glt> uploaded 1703936 / 8519680 bytes (20%) of your file. gzi2nwh4#974 2015-08-14_19:59:16.382482Z: <Encoder for h2glt> uploaded 1835008 / 8519680 bytes (21%) of your file. gzi2nwh4#983 2015-08-14_19:59:16.499439Z: <Encoder for h2glt> uploaded 1966080 / 8519680 bytes (23%) of your file. gzi2nwh4#992 2015-08-14_19:59:16.618716Z: <Encoder for h2glt> uploaded 2097152 / 8519680 bytes (24%) of your file. gzi2nwh4#1001 2015-08-14_19:59:16.737745Z: <Encoder for h2glt> uploaded 2228224 / 8519680 bytes (26%) of your file. gzi2nwh4#1010 2015-08-14_19:59:16.857203Z: <Encoder for h2glt> uploaded 2359296 / 8519680 bytes (27%) of your file. gzi2nwh4#1019 2015-08-14_19:59:16.978866Z: <Encoder for h2glt> uploaded 2490368 / 8519680 bytes (29%) of your file. gzi2nwh4#1028 2015-08-14_19:59:17.098858Z: <Encoder for h2glt> uploaded 2621440 / 8519680 bytes (30%) of your file. gzi2nwh4#1037 2015-08-14_19:59:17.214921Z: <Encoder for h2glt> uploaded 2752512 / 8519680 bytes (32%) of your file. gzi2nwh4#1046 2015-08-14_19:59:17.332566Z: <Encoder for h2glt> uploaded 2883584 / 8519680 bytes (33%) of your file. gzi2nwh4#1055 2015-08-14_19:59:17.452060Z: <Encoder for h2glt> uploaded 3014656 / 8519680 bytes (35%) of your file. gzi2nwh4#1064 2015-08-14_19:59:17.569375Z: <Encoder for h2glt> uploaded 3145728 / 8519680 bytes (36%) of your file. gzi2nwh4#1073 2015-08-14_19:59:17.686240Z: <Encoder for h2glt> uploaded 3276800 / 8519680 bytes (38%) of your file. gzi2nwh4#1082 2015-08-14_19:59:17.843214Z: <Encoder for h2glt> uploaded 3407872 / 8519680 bytes (40%) of your file. gzi2nwh4#1091 2015-08-14_19:59:17.960306Z: <Encoder for h2glt> uploaded 3538944 / 8519680 bytes (41%) of your file. gzi2nwh4#1100 2015-08-14_19:59:18.080105Z: <Encoder for h2glt> uploaded 3670016 / 8519680 bytes (43%) of your file. gzi2nwh4#1109 2015-08-14_19:59:18.198580Z: <Encoder for h2glt> uploaded 3801088 / 8519680 bytes (44%) of your file. gzi2nwh4#1118 2015-08-14_19:59:18.314532Z: <Encoder for h2glt> uploaded 3932160 / 8519680 bytes (46%) of your file. gzi2nwh4#1127 2015-08-14_19:59:18.434286Z: <Encoder for h2glt> uploaded 4063232 / 8519680 bytes (47%) of your file. gzi2nwh4#1136 2015-08-14_19:59:18.549338Z: <Encoder for h2glt> uploaded 4194304 / 8519680 bytes (49%) of your file. gzi2nwh4#1145 2015-08-14_19:59:18.669250Z: <Encoder for h2glt> uploaded 4325376 / 8519680 bytes (50%) of your file. gzi2nwh4#1154 2015-08-14_19:59:18.790509Z: <Encoder for h2glt> uploaded 4456448 / 8519680 bytes (52%) of your file. gzi2nwh4#1163 2015-08-14_19:59:18.910815Z: <Encoder for h2glt> uploaded 4587520 / 8519680 bytes (53%) of your file. gzi2nwh4#1172 2015-08-14_19:59:19.026370Z: <Encoder for h2glt> uploaded 4718592 / 8519680 bytes (55%) of your file. gzi2nwh4#1181 2015-08-14_19:59:19.224390Z: <Encoder for h2glt> uploaded 4849664 / 8519680 bytes (56%) of your file. gzi2nwh4#1190 2015-08-14_19:59:19.385905Z: <Encoder for h2glt> uploaded 4980736 / 8519680 bytes (58%) of your file. gzi2nwh4#1199 2015-08-14_19:59:19.502284Z: <Encoder for h2glt> uploaded 5111808 / 8519680 bytes (60%) of your file. gzi2nwh4#1208 2015-08-14_19:59:19.618499Z: <Encoder for h2glt> uploaded 5242880 / 8519680 bytes (61%) of your file. gzi2nwh4#1217 2015-08-14_19:59:19.782355Z: <Encoder for h2glt> uploaded 5373952 / 8519680 bytes (63%) of your file. gzi2nwh4#1226 2015-08-14_19:59:19.898144Z: <Encoder for h2glt> uploaded 5505024 / 8519680 bytes (64%) of your file. gzi2nwh4#1235 2015-08-14_19:59:20.017352Z: <Encoder for h2glt> uploaded 5636096 / 8519680 bytes (66%) of your file. gzi2nwh4#1244 2015-08-14_19:59:20.138521Z: <Encoder for h2glt> uploaded 5767168 / 8519680 bytes (67%) of your file. gzi2nwh4#1253 2015-08-14_19:59:20.271048Z: <Encoder for h2glt> uploaded 5898240 / 8519680 bytes (69%) of your file. gzi2nwh4#1262 2015-08-14_19:59:20.390491Z: <Encoder for h2glt> uploaded 6029312 / 8519680 bytes (70%) of your file. gzi2nwh4#1271 2015-08-14_19:59:20.510556Z: <Encoder for h2glt> uploaded 6160384 / 8519680 bytes (72%) of your file. gzi2nwh4#1280 2015-08-14_19:59:20.626941Z: <Encoder for h2glt> uploaded 6291456 / 8519680 bytes (73%) of your file. gzi2nwh4#1289 2015-08-14_19:59:20.750680Z: <Encoder for h2glt> uploaded 6422528 / 8519680 bytes (75%) of your file. gzi2nwh4#1298 2015-08-14_19:59:20.869395Z: <Encoder for h2glt> uploaded 6553600 / 8519680 bytes (76%) of your file. gzi2nwh4#1307 2015-08-14_19:59:20.986284Z: <Encoder for h2glt> uploaded 6684672 / 8519680 bytes (78%) of your file. gzi2nwh4#1316 2015-08-14_19:59:21.111241Z: <Encoder for h2glt> uploaded 6815744 / 8519680 bytes (80%) of your file. gzi2nwh4#1325 2015-08-14_19:59:21.230094Z: <Encoder for h2glt> uploaded 6946816 / 8519680 bytes (81%) of your file. gzi2nwh4#1334 2015-08-14_19:59:21.350500Z: <Encoder for h2glt> uploaded 7077888 / 8519680 bytes (83%) of your file. gzi2nwh4#1343 2015-08-14_19:59:21.478198Z: <Encoder for h2glt> uploaded 7208960 / 8519680 bytes (84%) of your file. gzi2nwh4#1352 2015-08-14_19:59:21.610661Z: <Encoder for h2glt> uploaded 7340032 / 8519680 bytes (86%) of your file. gzi2nwh4#1361 2015-08-14_19:59:21.726507Z: <Encoder for h2glt> uploaded 7471104 / 8519680 bytes (87%) of your file. gzi2nwh4#1370 2015-08-14_19:59:21.846560Z: <Encoder for h2glt> uploaded 7602176 / 8519680 bytes (89%) of your file. gzi2nwh4#1379 2015-08-14_19:59:21.962270Z: <Encoder for h2glt> uploaded 7733248 / 8519680 bytes (90%) of your file. gzi2nwh4#1388 2015-08-14_19:59:22.086476Z: <Encoder for h2glt> uploaded 7864320 / 8519680 bytes (92%) of your file. gzi2nwh4#1394 2015-08-14_19:59:22.090320Z: send_segment(60) gzi2nwh4#1395 2015-08-14_19:59:22.090339Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1396 2015-08-14_19:59:22.206284Z: put_block done gzi2nwh4#1397 2015-08-14_19:59:22.206389Z: <Encoder for h2glt> uploaded 7995392 / 8519680 bytes (93%) of your file. gzi2nwh4#1398 2015-08-14_19:59:22.206727Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1399 2015-08-14_19:59:22.207600Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1400 2015-08-14_19:59:22.208456Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1401 2015-08-14_19:59:22.208765Z: closed hash [61]: 131072B gzi2nwh4#1402 2015-08-14_19:59:22.208837Z: plaintext leaf hash [61] is 2lyukfjv6kubtn2v3vzdzazozozouphrb5ekhkx2zobv7j7k2wwq gzi2nwh4#1403 2015-08-14_19:59:22.210309Z: send_segment(61) gzi2nwh4#1404 2015-08-14_19:59:22.210329Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1405 2015-08-14_19:59:22.326303Z: put_block done gzi2nwh4#1406 2015-08-14_19:59:22.326402Z: <Encoder for h2glt> uploaded 8126464 / 8519680 bytes (95%) of your file. gzi2nwh4#1407 2015-08-14_19:59:22.326710Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1408 2015-08-14_19:59:22.327492Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1409 2015-08-14_19:59:22.328264Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1410 2015-08-14_19:59:22.328566Z: closed hash [62]: 131072B gzi2nwh4#1411 2015-08-14_19:59:22.328625Z: plaintext leaf hash [62] is czub42tbenefcwlbg6vwch4dmukdamawsno5qs7n73lnaspp4zja gzi2nwh4#1412 2015-08-14_19:59:22.330092Z: send_segment(62) gzi2nwh4#1413 2015-08-14_19:59:22.330111Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1414 2015-08-14_19:59:22.449037Z: put_block done gzi2nwh4#1415 2015-08-14_19:59:22.449143Z: <Encoder for h2glt> uploaded 8257536 / 8519680 bytes (96%) of your file. gzi2nwh4#1416 2015-08-14_19:59:22.449469Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1417 2015-08-14_19:59:22.450352Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1418 2015-08-14_19:59:22.451214Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1419 2015-08-14_19:59:22.451550Z: closed hash [63]: 131072B gzi2nwh4#1420 2015-08-14_19:59:22.451620Z: plaintext leaf hash [63] is 3pcr4jbg2spryvhdaaavig3lgokdaf4p5qgxvuta57eubd3uxpvq gzi2nwh4#1421 2015-08-14_19:59:22.453263Z: send_segment(63) gzi2nwh4#1422 2015-08-14_19:59:22.453285Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1423 2015-08-14_19:59:22.563496Z: put_block done gzi2nwh4#1424 2015-08-14_19:59:22.563594Z: <Encoder for h2glt> uploaded 8388608 / 8519680 bytes (98%) of your file. gzi2nwh4#1425 2015-08-14_19:59:22.563935Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1426 2015-08-14_19:59:22.564817Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1427 2015-08-14_19:59:22.565680Z: read_encrypted handling 28371B-sized chunk gzi2nwh4#1428 2015-08-14_19:59:22.567620Z: send_segment(64) gzi2nwh4#1429 2015-08-14_19:59:22.567641Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1430 2015-08-14_19:59:22.687463Z: put_block done gzi2nwh4#1431 2015-08-14_19:59:22.687562Z: <Encoder for h2glt> uploaded 8519680 / 8519680 bytes (100%) of your file. gzi2nwh4#1432 2015-08-14_19:59:22.687740Z: sending crypttext hash tree gzi2nwh4#1433 2015-08-14_19:59:22.690135Z: sending block hash trees gzi2nwh4#1434 2015-08-14_19:59:22.692389Z: sending all share hash trees gzi2nwh4#1435 2015-08-14_19:59:22.693001Z: sending uri_extension gzi2nwh4#1436 2015-08-14_19:59:22.693263Z: uri_extension_data is {'num_segments': 65, 'crypttext_hash': 'gmwy4la2px3szrcudxrj6ryb4da7nikcl4skfzwlwzhl6pr7n2vq', 'tail_codec_params': '130771-1-1', 'share_root_hash': 'kfrkjzsfco5snmea7iww4vmjjse5ayjn7ducf76lqli5ob47334q', 'crypttext_root_hash': 'd5cv6otfclluryntwi5dz6dzflksmokimc5goto7ndkz2kqnoagq', 'codec_params': '131072-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 131072, 'size': 8519379} gzi2nwh4#1437 2015-08-14_19:59:22.693882Z: closing shareholders gzi2nwh4#1438 2015-08-14_19:59:24.783435Z: upload done gzi2nwh4#1439 2015-08-14_19:59:24.784450Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 99 gzi2nwh4#1440 2015-08-14_19:59:24.844047Z: CHKUploader starting gzi2nwh4#1441 2015-08-14_19:59:24.844089Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3f7b48> gzi2nwh4#1442 2015-08-14_19:59:24.844121Z: creating Encoder <Encoder for unknown storage index> gzi2nwh4#1443 2015-08-14_19:59:24.844162Z: file size: 645271 gzi2nwh4#1444 2015-08-14_19:59:24.844221Z: my encoding parameters: (1, 1, 1, 131072) gzi2nwh4#1445 2015-08-14_19:59:24.844249Z: got encoding parameters: 1/1/1 131072 gzi2nwh4#1446 2015-08-14_19:59:24.844259Z: now setting up codec gzi2nwh4#1447 2015-08-14_19:59:24.847820Z: using storage index h2fei gzi2nwh4#1448 2015-08-14_19:59:24.847861Z: <Tahoe2ServerSelector for upload h2fei>(h2fei): starting gzi2nwh4#1449 2015-08-14_19:59:24.965356Z: <Tahoe2ServerSelector for upload h2fei>(h2fei): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#1450 2015-08-14_19:59:24.965518Z: <Tahoe2ServerSelector for upload h2fei>(h2fei): server selection successful for <Tahoe2ServerSelector for upload h2fei>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#1451 2015-08-14_19:59:24.965558Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#1452 2015-08-14_19:59:24.965639Z: <Encoder for h2fei> starting gzi2nwh4#1453 2015-08-14_19:59:24.965790Z: starting shareholders gzi2nwh4#1454 2015-08-14_19:59:24.966643Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1455 2015-08-14_19:59:24.967494Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1456 2015-08-14_19:59:24.968343Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1457 2015-08-14_19:59:24.968646Z: closed hash [0]: 131072B gzi2nwh4#1458 2015-08-14_19:59:24.968714Z: plaintext leaf hash [0] is r7ftjqxuhfb4fneu4qlpvkzzwy4ixhhih7bjhmz7wfvnsktsmuaq gzi2nwh4#1459 2015-08-14_19:59:24.970175Z: send_segment(0) gzi2nwh4#1460 2015-08-14_19:59:24.970192Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1461 2015-08-14_19:59:25.308685Z: put_block done gzi2nwh4#1462 2015-08-14_19:59:25.308789Z: <Encoder for h2fei> uploaded 131072 / 655360 bytes (20%) of your file. gzi2nwh4#1463 2015-08-14_19:59:25.309115Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1464 2015-08-14_19:59:25.310000Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1465 2015-08-14_19:59:25.310864Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1466 2015-08-14_19:59:25.311203Z: closed hash [1]: 131072B gzi2nwh4#1467 2015-08-14_19:59:25.311269Z: plaintext leaf hash [1] is jg4gnvxhmhmec5nrguntnrs75s6iwb6eablsnp3gasfxmbq7mlyq gzi2nwh4#1468 2015-08-14_19:59:25.312910Z: send_segment(1) gzi2nwh4#1469 2015-08-14_19:59:25.312931Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1470 2015-08-14_19:59:25.427310Z: put_block done gzi2nwh4#1471 2015-08-14_19:59:25.427409Z: <Encoder for h2fei> uploaded 262144 / 655360 bytes (40%) of your file. gzi2nwh4#1472 2015-08-14_19:59:25.427725Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1473 2015-08-14_19:59:25.428509Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1474 2015-08-14_19:59:25.429282Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1475 2015-08-14_19:59:25.429584Z: closed hash [2]: 131072B gzi2nwh4#1476 2015-08-14_19:59:25.429656Z: plaintext leaf hash [2] is it3khulmol2jwmhk5tsob2opd6h2wlsnotlpqmv4awjkqzghdgaq gzi2nwh4#1477 2015-08-14_19:59:25.431195Z: send_segment(2) gzi2nwh4#1478 2015-08-14_19:59:25.431214Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1479 2015-08-14_19:59:25.546415Z: put_block done gzi2nwh4#1480 2015-08-14_19:59:25.546516Z: <Encoder for h2fei> uploaded 393216 / 655360 bytes (60%) of your file. gzi2nwh4#1481 2015-08-14_19:59:25.546835Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1482 2015-08-14_19:59:25.547648Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1483 2015-08-14_19:59:25.548450Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1484 2015-08-14_19:59:25.548768Z: closed hash [3]: 131072B gzi2nwh4#1485 2015-08-14_19:59:25.548831Z: plaintext leaf hash [3] is ulrhwo7d5xup47d5n4kxcjk7znz2422lick7wyhdzodvbyl5wegq gzi2nwh4#1486 2015-08-14_19:59:25.550348Z: send_segment(3) gzi2nwh4#1487 2015-08-14_19:59:25.550368Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1488 2015-08-14_19:59:25.667967Z: put_block done gzi2nwh4#1489 2015-08-14_19:59:25.668067Z: <Encoder for h2fei> uploaded 524288 / 655360 bytes (80%) of your file. gzi2nwh4#1490 2015-08-14_19:59:25.668375Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1491 2015-08-14_19:59:25.669229Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1492 2015-08-14_19:59:25.670139Z: read_encrypted handling 18583B-sized chunk gzi2nwh4#1493 2015-08-14_19:59:25.671714Z: send_segment(4) gzi2nwh4#1494 2015-08-14_19:59:25.671735Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1495 2015-08-14_19:59:25.779546Z: put_block done gzi2nwh4#1496 2015-08-14_19:59:25.779648Z: <Encoder for h2fei> uploaded 655360 / 655360 bytes (100%) of your file. gzi2nwh4#1497 2015-08-14_19:59:25.779830Z: sending crypttext hash tree gzi2nwh4#1498 2015-08-14_19:59:25.780663Z: sending block hash trees gzi2nwh4#1499 2015-08-14_19:59:25.781375Z: sending all share hash trees gzi2nwh4#1500 2015-08-14_19:59:25.781971Z: sending uri_extension gzi2nwh4#1501 2015-08-14_19:59:25.782198Z: uri_extension_data is {'num_segments': 5, 'crypttext_hash': '5lyr42cwkbrfnhfxdskyxamwj3eiqohhj4r62v72iavwfl6bim7q', 'tail_codec_params': '120983-1-1', 'share_root_hash': '3cijmogyhq4hpfzvdwq65w3cygb6r2pkuoeskqxewgmzykhhdyoa', 'crypttext_root_hash': 'lq43s5eolutc44ip227kags4lejvjdtb3ipihofzeet22yjr26na', 'codec_params': '131072-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 131072, 'size': 645271} gzi2nwh4#1502 2015-08-14_19:59:25.782805Z: closing shareholders gzi2nwh4#1503 2015-08-14_19:59:25.981746Z: upload done gzi2nwh4#1504 2015-08-14_19:59:25.982604Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 98 gzi2nwh4#1505 2015-08-14_19:59:26.051620Z: CHKUploader starting gzi2nwh4#1506 2015-08-14_19:59:26.051686Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f3f7cb0> gzi2nwh4#1507 2015-08-14_19:59:26.051733Z: creating Encoder <Encoder for unknown storage index> gzi2nwh4#1508 2015-08-14_19:59:26.051785Z: file size: 1293042 gzi2nwh4#1509 2015-08-14_19:59:26.051846Z: my encoding parameters: (1, 1, 1, 131072) gzi2nwh4#1510 2015-08-14_19:59:26.051875Z: got encoding parameters: 1/1/1 131072 gzi2nwh4#1511 2015-08-14_19:59:26.051884Z: now setting up codec gzi2nwh4#1512 2015-08-14_19:59:26.058721Z: using storage index kdzug gzi2nwh4#1513 2015-08-14_19:59:26.058763Z: <Tahoe2ServerSelector for upload kdzug>(kdzug): starting gzi2nwh4#1514 2015-08-14_19:59:26.246807Z: <Tahoe2ServerSelector for upload kdzug>(kdzug): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#1515 2015-08-14_19:59:26.246968Z: <Tahoe2ServerSelector for upload kdzug>(kdzug): server selection successful for <Tahoe2ServerSelector for upload kdzug>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#1516 2015-08-14_19:59:26.247009Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#1517 2015-08-14_19:59:26.247090Z: <Encoder for kdzug> starting gzi2nwh4#1518 2015-08-14_19:59:26.247250Z: starting shareholders gzi2nwh4#1519 2015-08-14_19:59:26.248117Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1520 2015-08-14_19:59:26.248967Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1521 2015-08-14_19:59:26.249741Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1522 2015-08-14_19:59:26.250041Z: closed hash [0]: 131072B gzi2nwh4#1523 2015-08-14_19:59:26.250101Z: plaintext leaf hash [0] is fqw56ywniyusqmed72ey7kgnobrjlyejn57xp2secvfnfjfghz4q gzi2nwh4#1524 2015-08-14_19:59:26.251599Z: send_segment(0) gzi2nwh4#1525 2015-08-14_19:59:26.251616Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1526 2015-08-14_19:59:26.414078Z: put_block done gzi2nwh4#1527 2015-08-14_19:59:26.414185Z: <Encoder for kdzug> uploaded 131072 / 1310720 bytes (10%) of your file. gzi2nwh4#1528 2015-08-14_19:59:26.414513Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1529 2015-08-14_19:59:26.415400Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1530 2015-08-14_19:59:26.416264Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1531 2015-08-14_19:59:26.416599Z: closed hash [1]: 131072B gzi2nwh4#1532 2015-08-14_19:59:26.416665Z: plaintext leaf hash [1] is gggvrn774b7pxzy6w2wdjsppabtt42zn4qtaulombzn5wehh3nxq gzi2nwh4#1533 2015-08-14_19:59:26.418361Z: send_segment(1) gzi2nwh4#1534 2015-08-14_19:59:26.418405Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1535 2015-08-14_19:59:26.530791Z: put_block done gzi2nwh4#1536 2015-08-14_19:59:26.530891Z: <Encoder for kdzug> uploaded 262144 / 1310720 bytes (20%) of your file. gzi2nwh4#1537 2015-08-14_19:59:26.531213Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1538 2015-08-14_19:59:26.532004Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1539 2015-08-14_19:59:26.532776Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1540 2015-08-14_19:59:26.533077Z: closed hash [2]: 131072B gzi2nwh4#1541 2015-08-14_19:59:26.533137Z: plaintext leaf hash [2] is ut4va3py6lgrcewt7l3b3g2iuwce3rom4lxjesk7jaheqsalq3iq gzi2nwh4#1542 2015-08-14_19:59:26.534667Z: send_segment(2) gzi2nwh4#1543 2015-08-14_19:59:26.534692Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1544 2015-08-14_19:59:26.654973Z: put_block done gzi2nwh4#1545 2015-08-14_19:59:26.655165Z: <Encoder for kdzug> uploaded 393216 / 1310720 bytes (30%) of your file. gzi2nwh4#1546 2015-08-14_19:59:26.655664Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1547 2015-08-14_19:59:26.656562Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1548 2015-08-14_19:59:26.657428Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1549 2015-08-14_19:59:26.657772Z: closed hash [3]: 131072B gzi2nwh4#1550 2015-08-14_19:59:26.657840Z: plaintext leaf hash [3] is y2j4cun22h6f44qbr6vo34325dnivyttobjc54oo2ftqeajpug2a gzi2nwh4#1551 2015-08-14_19:59:26.659567Z: send_segment(3) gzi2nwh4#1552 2015-08-14_19:59:26.659600Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1553 2015-08-14_19:59:26.772586Z: put_block done gzi2nwh4#1554 2015-08-14_19:59:26.772699Z: <Encoder for kdzug> uploaded 524288 / 1310720 bytes (40%) of your file. gzi2nwh4#1555 2015-08-14_19:59:26.773021Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1556 2015-08-14_19:59:26.773861Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1557 2015-08-14_19:59:26.774627Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1558 2015-08-14_19:59:26.774935Z: closed hash [4]: 131072B gzi2nwh4#1559 2015-08-14_19:59:26.774995Z: plaintext leaf hash [4] is j37tleornitie7zuq4wbd25wozis2mteo7wvxa66gkqjuufhrpxq gzi2nwh4#1560 2015-08-14_19:59:26.776460Z: send_segment(4) gzi2nwh4#1561 2015-08-14_19:59:26.776493Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1562 2015-08-14_19:59:26.891527Z: put_block done gzi2nwh4#1563 2015-08-14_19:59:26.891633Z: <Encoder for kdzug> uploaded 655360 / 1310720 bytes (50%) of your file. gzi2nwh4#1564 2015-08-14_19:59:26.891956Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1565 2015-08-14_19:59:26.892801Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1566 2015-08-14_19:59:26.893565Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1567 2015-08-14_19:59:26.893872Z: closed hash [5]: 131072B gzi2nwh4#1568 2015-08-14_19:59:26.893933Z: plaintext leaf hash [5] is g74222vueyevzq45oppxrgvpycyq5tzherhck65jfojmnivql3lq gzi2nwh4#1569 2015-08-14_19:59:26.895395Z: send_segment(5) gzi2nwh4#1570 2015-08-14_19:59:26.895414Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1571 2015-08-14_19:59:27.015477Z: put_block done gzi2nwh4#1572 2015-08-14_19:59:27.015578Z: <Encoder for kdzug> uploaded 786432 / 1310720 bytes (60%) of your file. gzi2nwh4#1573 2015-08-14_19:59:27.015923Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1574 2015-08-14_19:59:27.016716Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1575 2015-08-14_19:59:27.017482Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1576 2015-08-14_19:59:27.017822Z: closed hash [6]: 131072B gzi2nwh4#1577 2015-08-14_19:59:27.017883Z: plaintext leaf hash [6] is j67wjp5nmguwpoku4vbxllz6ipoegfsa2l6vxglief4tq7up2f7a gzi2nwh4#1578 2015-08-14_19:59:27.019345Z: send_segment(6) gzi2nwh4#1579 2015-08-14_19:59:27.019365Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1580 2015-08-14_19:59:27.138680Z: put_block done gzi2nwh4#1581 2015-08-14_19:59:27.138788Z: <Encoder for kdzug> uploaded 917504 / 1310720 bytes (70%) of your file. gzi2nwh4#1582 2015-08-14_19:59:27.139115Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1583 2015-08-14_19:59:27.140001Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1584 2015-08-14_19:59:27.140866Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1585 2015-08-14_19:59:27.141202Z: closed hash [7]: 131072B gzi2nwh4#1586 2015-08-14_19:59:27.141268Z: plaintext leaf hash [7] is 3n5l5cenud735pcov35u2cghcbu5atzcdudqrbobdi5nhv6x4uvq gzi2nwh4#1587 2015-08-14_19:59:27.142949Z: send_segment(7) gzi2nwh4#1588 2015-08-14_19:59:27.142975Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1589 2015-08-14_19:59:27.254379Z: put_block done gzi2nwh4#1590 2015-08-14_19:59:27.254482Z: <Encoder for kdzug> uploaded 1048576 / 1310720 bytes (80%) of your file. gzi2nwh4#1591 2015-08-14_19:59:27.254805Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1592 2015-08-14_19:59:27.255641Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1593 2015-08-14_19:59:27.256414Z: read_encrypted handling 28672B-sized chunk gzi2nwh4#1594 2015-08-14_19:59:27.256722Z: closed hash [8]: 131072B gzi2nwh4#1595 2015-08-14_19:59:27.256783Z: plaintext leaf hash [8] is hag2mwv7ks5mdcni2lfbhmd2ugcucl4u6ysio2wbabci7qanvv3q gzi2nwh4#1596 2015-08-14_19:59:27.258246Z: send_segment(8) gzi2nwh4#1597 2015-08-14_19:59:27.258265Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1598 2015-08-14_19:59:27.371455Z: put_block done gzi2nwh4#1599 2015-08-14_19:59:27.371556Z: <Encoder for kdzug> uploaded 1179648 / 1310720 bytes (90%) of your file. gzi2nwh4#1600 2015-08-14_19:59:27.371865Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1601 2015-08-14_19:59:27.372648Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1602 2015-08-14_19:59:27.373418Z: read_encrypted handling 10994B-sized chunk gzi2nwh4#1603 2015-08-14_19:59:27.374762Z: send_segment(9) gzi2nwh4#1604 2015-08-14_19:59:27.374779Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1605 2015-08-14_19:59:27.476623Z: put_block done gzi2nwh4#1606 2015-08-14_19:59:27.476736Z: <Encoder for kdzug> uploaded 1310720 / 1310720 bytes (100%) of your file. gzi2nwh4#1607 2015-08-14_19:59:27.476905Z: sending crypttext hash tree gzi2nwh4#1608 2015-08-14_19:59:27.477833Z: sending block hash trees gzi2nwh4#1609 2015-08-14_19:59:27.478635Z: sending all share hash trees gzi2nwh4#1610 2015-08-14_19:59:27.479229Z: sending uri_extension gzi2nwh4#1611 2015-08-14_19:59:27.479458Z: uri_extension_data is {'num_segments': 10, 'crypttext_hash': '7jp5eritd7yohuuntlvsorediqxii67cpxnp5rgcjyphl2tor2xa', 'tail_codec_params': '113394-1-1', 'share_root_hash': 'oy73gwu3pjkuxjp6jcgzyd35fffev54qwbjf5mihjh5xeomff5zq', 'crypttext_root_hash': 'pkff6tgiamojh3nh47eslu6qikov7xmzyujov33xw7jj6zcpgdhq', 'codec_params': '131072-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 131072, 'size': 1293042} gzi2nwh4#1612 2015-08-14_19:59:27.480066Z: closing shareholders gzi2nwh4#1613 2015-08-14_19:59:27.758158Z: upload done gzi2nwh4#1614 2015-08-14_19:59:27.758922Z: web: 127.0.0.1 PUT /uri/[CENSORED].. 200 99 gzi2nwh4#1615 2015-08-14_19:59:27.864428Z: CHKUploader starting gzi2nwh4#1616 2015-08-14_19:59:27.864470Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f5ade18> gzi2nwh4#1617 2015-08-14_19:59:27.864504Z: creating Encoder <Encoder for unknown storage index> gzi2nwh4#1618 2015-08-14_19:59:27.864543Z: file size: 76972 gzi2nwh4#1619 2015-08-14_19:59:27.864598Z: my encoding parameters: (1, 1, 1, 76972) gzi2nwh4#1620 2015-08-14_19:59:27.864626Z: got encoding parameters: 1/1/1 76972 gzi2nwh4#1621 2015-08-14_19:59:27.864636Z: now setting up codec gzi2nwh4#1622 2015-08-14_19:59:27.865212Z: using storage index bc7xg gzi2nwh4#1623 2015-08-14_19:59:27.865250Z: <Tahoe2ServerSelector for upload bc7xg>(bc7xg): starting gzi2nwh4#1624 2015-08-14_19:59:27.957665Z: <Tahoe2ServerSelector for upload bc7xg>(bc7xg): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#1625 2015-08-14_19:59:27.957936Z: <Tahoe2ServerSelector for upload bc7xg>(bc7xg): server selection successful for <Tahoe2ServerSelector for upload bc7xg>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#1626 2015-08-14_19:59:27.957999Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#1627 2015-08-14_19:59:27.958127Z: <Encoder for bc7xg> starting gzi2nwh4#1628 2015-08-14_19:59:27.958339Z: starting shareholders gzi2nwh4#1629 2015-08-14_19:59:27.959780Z: read_encrypted handling 51200B-sized chunk gzi2nwh4#1630 2015-08-14_19:59:27.961236Z: read_encrypted handling 25772B-sized chunk gzi2nwh4#1631 2015-08-14_19:59:27.961695Z: closed hash [0]: 76972B gzi2nwh4#1632 2015-08-14_19:59:27.961792Z: plaintext leaf hash [0] is c6ljqqpowsorcw5pp274ql2qylufdbgklugzijc2mkdegbm4ljva gzi2nwh4#1633 2015-08-14_19:59:27.963311Z: send_segment(0) gzi2nwh4#1634 2015-08-14_19:59:27.963339Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1635 2015-08-14_19:59:28.123022Z: put_block done gzi2nwh4#1636 2015-08-14_19:59:28.123121Z: <Encoder for bc7xg> uploaded 76972 / 76972 bytes (100%) of your file. gzi2nwh4#1637 2015-08-14_19:59:28.123291Z: sending crypttext hash tree gzi2nwh4#1638 2015-08-14_19:59:28.124001Z: sending block hash trees gzi2nwh4#1639 2015-08-14_19:59:28.124607Z: sending all share hash trees gzi2nwh4#1640 2015-08-14_19:59:28.125221Z: sending uri_extension gzi2nwh4#1641 2015-08-14_19:59:28.125514Z: uri_extension_data is {'num_segments': 1, 'crypttext_hash': '5hy3qxzx74zev6qxqicf7f6uw6x3ksxt3iaud5edwcwotranf4qa', 'tail_codec_params': '76972-1-1', 'share_root_hash': 'tz5yuzytreox6f7mk4ddzg3yykubsbvgr5pvdjlxvxlpumxrrlbq', 'crypttext_root_hash': 'uci6o3xbgvspgz4veoq4vaypbrzuhot5ush2dj564yvm6daxzpgq', 'codec_params': '76972-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 76972, 'size': 76972} gzi2nwh4#1642 2015-08-14_19:59:28.126198Z: closing shareholders gzi2nwh4#1643 2015-08-14_19:59:28.397949Z: upload done gzi2nwh4#1644 2015-08-14_19:59:28.399173Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=mkdir-immutable 200 102 gzi2nwh4#1645 2015-08-14_19:59:28.450803Z: CHKUploader starting gzi2nwh4#1646 2015-08-14_19:59:28.450845Z: starting upload of <allmydata.immutable.upload.EncryptAnUploadable instance at 0x7f729f465cf8> gzi2nwh4#1647 2015-08-14_19:59:28.450881Z: creating Encoder <Encoder for unknown storage index> gzi2nwh4#1648 2015-08-14_19:59:28.450922Z: file size: 4151 gzi2nwh4#1649 2015-08-14_19:59:28.451014Z: my encoding parameters: (1, 1, 1, 4151) gzi2nwh4#1650 2015-08-14_19:59:28.451045Z: got encoding parameters: 1/1/1 4151 gzi2nwh4#1651 2015-08-14_19:59:28.451055Z: now setting up codec gzi2nwh4#1652 2015-08-14_19:59:28.451257Z: using storage index wianb gzi2nwh4#1653 2015-08-14_19:59:28.451292Z: <Tahoe2ServerSelector for upload wianb>(wianb): starting gzi2nwh4#1654 2015-08-14_19:59:28.565584Z: <Tahoe2ServerSelector for upload wianb>(wianb): response to allocate_buckets() from server 6dwd2q: alreadygot=(), allocated=(0,) gzi2nwh4#1655 2015-08-14_19:59:28.565759Z: <Tahoe2ServerSelector for upload wianb>(wianb): server selection successful for <Tahoe2ServerSelector for upload wianb>: placed all 1 shares, want to place shares on at least 1 servers such that any 1 of them have enough shares to recover the file, sent 1 queries to 1 servers, 1 queries placed some shares, 0 placed none (of which 0 placed none due to the server being full and 0 placed none due to an error): pretty_print_merged: sh0: 6dwd2q4w, self.use_trackers: ['0: 6dwd2q'], self.preexisting_shares: gzi2nwh4#1656 2015-08-14_19:59:28.565798Z: set_shareholders; upload_trackers is ['0: 6dwd2q'], already_serverids is {} gzi2nwh4#1657 2015-08-14_19:59:28.565881Z: <Encoder for wianb> starting gzi2nwh4#1658 2015-08-14_19:59:28.566013Z: starting shareholders gzi2nwh4#1659 2015-08-14_19:59:28.566854Z: read_encrypted handling 4151B-sized chunk gzi2nwh4#1660 2015-08-14_19:59:28.566930Z: closed hash [0]: 4151B gzi2nwh4#1661 2015-08-14_19:59:28.567003Z: plaintext leaf hash [0] is neldvpuig7btee3fcbc3ss7jjyb5wa3pfrlciq2e5t7wqk6vvdpq gzi2nwh4#1662 2015-08-14_19:59:28.567161Z: send_segment(0) gzi2nwh4#1663 2015-08-14_19:59:28.567192Z: put_block to <WriteBucketProxy for node 6dwd2q> gzi2nwh4#1664 2015-08-14_19:59:28.567816Z: put_block done gzi2nwh4#1665 2015-08-14_19:59:28.567939Z: <Encoder for wianb> uploaded 4151 / 4151 bytes (100%) of your file. gzi2nwh4#1666 2015-08-14_19:59:28.568094Z: sending crypttext hash tree gzi2nwh4#1667 2015-08-14_19:59:28.568767Z: sending block hash trees gzi2nwh4#1668 2015-08-14_19:59:28.569386Z: sending all share hash trees gzi2nwh4#1669 2015-08-14_19:59:28.570008Z: sending uri_extension gzi2nwh4#1670 2015-08-14_19:59:28.570246Z: uri_extension_data is {'num_segments': 1, 'crypttext_hash': '3govd5hhcfybzqin3wgsdxhooxxrsvsqn55oeoppmon2robtm5ea', 'tail_codec_params': '4151-1-1', 'share_root_hash': 'ppkka3e6sz77go2ojmznwkzlgv3lclukpfufhtvgkdc3dlt6q2xq', 'crypttext_root_hash': '4x3p46hanu3bcxll6n2qseuiyd4ca4nnnjfnxeda4vrsvvli6izq', 'codec_params': '4151-1-1', 'codec_name': 'crs', 'total_shares': 1, 'needed_shares': 1, 'segment_size': 4151, 'size': 4151} gzi2nwh4#1671 2015-08-14_19:59:28.570888Z: closing shareholders gzi2nwh4#1672 2015-08-14_19:59:28.772181Z: upload done gzi2nwh4#1673 2015-08-14_19:59:28.773339Z: web: 127.0.0.1 POST /uri/[CENSORED]..?t=mkdir-immutable 200 101 gzi2nwh4#1674 2015-08-14_19:59:28.798450Z: SharemapUpdater(ia2sk): starting (MODE_READ) gzi2nwh4#1675 2015-08-14_19:59:28.798536Z: sending query to [6dwd2q], readsize=4000 gzi2nwh4#1676 2015-08-14_19:59:28.942096Z: got result from [6dwd2q], 0 shares gzi2nwh4#1677 2015-08-14_19:59:28.942174Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#1678 2015-08-14_19:59:28.942193Z: all queries are retired, no extra servers: done gzi2nwh4#1679 2015-08-14_19:59:28.942217Z: servermap: gzi2nwh4#1680 2015-08-14_19:59:28.942250Z: _got_results done gzi2nwh4#1681 2015-08-14_19:59:28.942276Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#1682 2015-08-14_19:59:28.942290Z: but we're not running gzi2nwh4#1683 2015-08-14_19:59:28.942770Z: web: 127.0.0.1 PUT /uri/[CENSORED]..?t=uri 410 390 gzi2nwh4#1684 2015-08-14_20:54:51.429384Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '127.0.0.1', 57428) gzi2nwh4#1685 2015-08-14_20:54:51.429415Z: Negotiation started gzi2nwh4#1686 2015-08-14_20:54:51.429467Z: initServer gzi2nwh4#1687 2015-08-14_20:54:51.429657Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '192.168.3.147', 50238) gzi2nwh4#1688 2015-08-14_20:54:51.429689Z: Negotiation started gzi2nwh4#1689 2015-08-14_20:54:51.429734Z: initServer gzi2nwh4#1690 2015-08-14_20:54:51.430172Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 127.0.0.1\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n' gzi2nwh4#1691 2015-08-14_20:54:51.430216Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl' gzi2nwh4#1692 2015-08-14_20:54:51.430234Z: handlePLAINTEXTServer: wantEncrypted=True gzi2nwh4#1693 2015-08-14_20:54:51.430280Z: startENCRYPTED(isClient=False) gzi2nwh4#1694 2015-08-14_20:54:51.430294Z: startTLS, client=False gzi2nwh4#1695 2015-08-14_20:54:51.434693Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1696 2015-08-14_20:54:51.434923Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 192.168.3.147\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n' gzi2nwh4#1697 2015-08-14_20:54:51.434962Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl' gzi2nwh4#1698 2015-08-14_20:54:51.434983Z: handlePLAINTEXTServer: wantEncrypted=True gzi2nwh4#1699 2015-08-14_20:54:51.435045Z: startENCRYPTED(isClient=False) gzi2nwh4#1700 2015-08-14_20:54:51.435065Z: startTLS, client=False gzi2nwh4#1701 2015-08-14_20:54:51.440927Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1702 2015-08-14_20:54:51.455921Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n' gzi2nwh4#1703 2015-08-14_20:54:51.455974Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n' gzi2nwh4#1704 2015-08-14_20:54:51.455998Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n' gzi2nwh4#1705 2015-08-14_20:54:51.456021Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: c96bed8982be4e79\r\n' gzi2nwh4#1706 2015-08-14_20:54:51.456042Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx\r\n' gzi2nwh4#1707 2015-08-14_20:54:51.456063Z: dataReceived(isClient=False,phase=1,options={}): '\r\n' gzi2nwh4#1708 2015-08-14_20:54:51.456113Z: evaluateHello(isClient=False): offer={'my-tub-id': 'xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx', 'last-connection': 'none 0', 'my-incarnation': 'c96bed8982be4e79', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1709 2015-08-14_20:54:51.456211Z: iAmTheMaster: False gzi2nwh4#1710 2015-08-14_20:54:51.456238Z: dataReceived(isClient=False,phase=2,options={}): 'banana-decision-version: 3\r\n' gzi2nwh4#1711 2015-08-14_20:54:51.456259Z: dataReceived(isClient=False,phase=2,options={}): 'current-connection: c96bed8982be4e79 1\r\n' gzi2nwh4#1712 2015-08-14_20:54:51.456280Z: dataReceived(isClient=False,phase=2,options={}): 'initial-vocab-table-index: 1 bb33\r\n' gzi2nwh4#1713 2015-08-14_20:54:51.456300Z: dataReceived(isClient=False,phase=2,options={}): '\r\n' gzi2nwh4#1714 2015-08-14_20:54:51.456315Z: handleDECIDING(isClient=False): banana-decision-version: 3 current-connection: c96bed8982be4e79 1 initial-vocab-table-index: 1 bb33 gzi2nwh4#1715 2015-08-14_20:54:51.456338Z: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': 'c96bed8982be4e79 1'} gzi2nwh4#1716 2015-08-14_20:54:51.456383Z: Negotiate.switchToBanana(isClient=False) gzi2nwh4#1717 2015-08-14_20:54:51.456398Z: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1} gzi2nwh4#1718 2015-08-14_20:54:51.458066Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n' gzi2nwh4#1719 2015-08-14_20:54:51.458110Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n' gzi2nwh4#1720 2015-08-14_20:54:51.458148Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n' gzi2nwh4#1721 2015-08-14_20:54:51.458187Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: c96bed8982be4e79\r\n' gzi2nwh4#1722 2015-08-14_20:54:51.458224Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx\r\n' gzi2nwh4#1723 2015-08-14_20:54:51.458261Z: dataReceived(isClient=False,phase=1,options={}): '\r\n' gzi2nwh4#1724 2015-08-14_20:54:51.458328Z: evaluateHello(isClient=False): offer={'my-tub-id': 'xfqdfwvwiywh7ebrn66hxdhcw4kdwyhx', 'last-connection': 'none 0', 'my-incarnation': 'c96bed8982be4e79', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1725 2015-08-14_20:54:51.458461Z: iAmTheMaster: False gzi2nwh4#1726 2015-08-14_20:54:51.458832Z: negotiationFailed: ConnectionDone gzi2nwh4#1727 2015-08-14_20:54:51.488218Z: Unhandled error in Deferred: gzi2nwh4#1728 2015-08-14_20:54:51.488549Z: Unhandled Error Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send d.callback(None) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback self._startRunCallbacks(result) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks self._runCallbacks() File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks current.result = callback(current.result, *args, **kw) --- <exception caught here> --- File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 215, in produce slicer = self.newSlicerFor(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor return topSlicer.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject raise Violation("cannot serialize %s (%s)" % (obj, name)) foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",) FAILURE: [CopiedFailure instance: Traceback from remote host -- Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send d.callback(None) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback self._startRunCallbacks(result) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks self._runCallbacks() File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks current.result = callback(current.result, *args, **kw) --- <excepti -- TRACEBACK ELIDED -- banana.py", line 215, in produce slicer = self.newSlicerFor(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor return topSlicer.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject raise Violation("cannot serialize %s (%s)" % (obj, name)) foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",) ] gzi2nwh4#1729 2015-08-14_20:55:11.780106Z: connection to xfqd lost gzi2nwh4#1730 2015-08-14_20:55:28.525037Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '127.0.0.1', 57434) gzi2nwh4#1731 2015-08-14_20:55:28.525060Z: Negotiation started gzi2nwh4#1732 2015-08-14_20:55:28.525093Z: initServer gzi2nwh4#1733 2015-08-14_20:55:28.525222Z: <Listener at 0x7f72a49d6170 on 34227 with tubs gzi2nwh4akud7r3ldeznjmxlumzf5rbl> accepting connection from IPv4Address(TCP, '192.168.3.147', 50244) gzi2nwh4#1734 2015-08-14_20:55:28.525233Z: Negotiation started gzi2nwh4#1735 2015-08-14_20:55:28.525255Z: initServer gzi2nwh4#1736 2015-08-14_20:55:28.525576Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 127.0.0.1\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n' gzi2nwh4#1737 2015-08-14_20:55:28.525629Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl' gzi2nwh4#1738 2015-08-14_20:55:28.525643Z: handlePLAINTEXTServer: wantEncrypted=True gzi2nwh4#1739 2015-08-14_20:55:28.525701Z: startENCRYPTED(isClient=False) gzi2nwh4#1740 2015-08-14_20:55:28.525712Z: startTLS, client=False gzi2nwh4#1741 2015-08-14_20:55:28.530385Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1742 2015-08-14_20:55:28.530601Z: dataReceived(isClient=False,phase=0,options={}): 'GET /id/gzi2nwh4akud7r3ldeznjmxlumzf5rbl HTTP/1.1\r\nHost: 192.168.3.147\r\nUpgrade: TLS/1.0\r\nConnection: Upgrade\r\n\r\n' gzi2nwh4#1743 2015-08-14_20:55:28.530628Z: handlePLAINTEXTServer: targetTubID='gzi2nwh4akud7r3ldeznjmxlumzf5rbl' gzi2nwh4#1744 2015-08-14_20:55:28.530642Z: handlePLAINTEXTServer: wantEncrypted=True gzi2nwh4#1745 2015-08-14_20:55:28.530689Z: startENCRYPTED(isClient=False) gzi2nwh4#1746 2015-08-14_20:55:28.530699Z: startTLS, client=False gzi2nwh4#1747 2015-08-14_20:55:28.533575Z: Negotiate.sendHello (isClient=False): {'my-incarnation': '37a4beb9e79a238a', 'my-tub-id': 'gzi2nwh4akud7r3ldeznjmxlumzf5rbl', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1748 2015-08-14_20:55:28.546900Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n' gzi2nwh4#1749 2015-08-14_20:55:28.546947Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n' gzi2nwh4#1750 2015-08-14_20:55:28.546967Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n' gzi2nwh4#1751 2015-08-14_20:55:28.546984Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: 1962200e72784097\r\n' gzi2nwh4#1752 2015-08-14_20:55:28.547002Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: wbvby75xnn5qw7n6shgkenpahnp7qhyt\r\n' gzi2nwh4#1753 2015-08-14_20:55:28.547019Z: dataReceived(isClient=False,phase=1,options={}): '\r\n' gzi2nwh4#1754 2015-08-14_20:55:28.547063Z: evaluateHello(isClient=False): offer={'my-tub-id': 'wbvby75xnn5qw7n6shgkenpahnp7qhyt', 'last-connection': 'none 0', 'my-incarnation': '1962200e72784097', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1755 2015-08-14_20:55:28.547152Z: iAmTheMaster: False gzi2nwh4#1756 2015-08-14_20:55:28.547173Z: dataReceived(isClient=False,phase=2,options={}): 'banana-decision-version: 3\r\n' gzi2nwh4#1757 2015-08-14_20:55:28.547192Z: dataReceived(isClient=False,phase=2,options={}): 'current-connection: 1962200e72784097 1\r\n' gzi2nwh4#1758 2015-08-14_20:55:28.547209Z: dataReceived(isClient=False,phase=2,options={}): 'initial-vocab-table-index: 1 bb33\r\n' gzi2nwh4#1759 2015-08-14_20:55:28.547225Z: dataReceived(isClient=False,phase=2,options={}): '\r\n' gzi2nwh4#1760 2015-08-14_20:55:28.547239Z: handleDECIDING(isClient=False): banana-decision-version: 3 current-connection: 1962200e72784097 1 initial-vocab-table-index: 1 bb33 gzi2nwh4#1761 2015-08-14_20:55:28.547259Z: Banana.acceptDecision: got {'banana-decision-version': '3', 'initial-vocab-table-index': '1 bb33', 'current-connection': '1962200e72784097 1'} gzi2nwh4#1762 2015-08-14_20:55:28.547297Z: Negotiate.switchToBanana(isClient=False) gzi2nwh4#1763 2015-08-14_20:55:28.547307Z: params: {'banana-decision-version': 3, 'initial-vocab-table-index': 1} gzi2nwh4#1764 2015-08-14_20:55:28.548657Z: dataReceived(isClient=False,phase=1,options={}): 'banana-negotiation-range: 3 3\r\n' gzi2nwh4#1765 2015-08-14_20:55:28.548692Z: dataReceived(isClient=False,phase=1,options={}): 'initial-vocab-table-range: 0 1\r\n' gzi2nwh4#1766 2015-08-14_20:55:28.548715Z: dataReceived(isClient=False,phase=1,options={}): 'last-connection: none 0\r\n' gzi2nwh4#1767 2015-08-14_20:55:28.548734Z: dataReceived(isClient=False,phase=1,options={}): 'my-incarnation: 1962200e72784097\r\n' gzi2nwh4#1768 2015-08-14_20:55:28.548753Z: dataReceived(isClient=False,phase=1,options={}): 'my-tub-id: wbvby75xnn5qw7n6shgkenpahnp7qhyt\r\n' gzi2nwh4#1769 2015-08-14_20:55:28.548772Z: dataReceived(isClient=False,phase=1,options={}): '\r\n' gzi2nwh4#1770 2015-08-14_20:55:28.548808Z: evaluateHello(isClient=False): offer={'my-tub-id': 'wbvby75xnn5qw7n6shgkenpahnp7qhyt', 'last-connection': 'none 0', 'my-incarnation': '1962200e72784097', 'initial-vocab-table-range': '0 1', 'banana-negotiation-range': '3 3'} gzi2nwh4#1771 2015-08-14_20:55:28.548885Z: iAmTheMaster: False gzi2nwh4#1772 2015-08-14_20:55:28.549109Z: negotiationFailed: ConnectionDone gzi2nwh4#1773 2015-08-14_20:55:28.572906Z: Unhandled error in Deferred: gzi2nwh4#1774 2015-08-14_20:55:28.573527Z: Unhandled Error Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send d.callback(None) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback self._startRunCallbacks(result) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks self._runCallbacks() File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks current.result = callback(current.result, *args, **kw) --- <exception caught here> --- File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 215, in produce slicer = self.newSlicerFor(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor return topSlicer.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject raise Violation("cannot serialize %s (%s)" % (obj, name)) foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",) FAILURE: [CopiedFailure instance: Traceback from remote host -- Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 107, in send d.callback(None) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 383, in callback self._startRunCallbacks(result) File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 491, in _startRunCallbacks self._runCallbacks() File "/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py", line 578, in _runCallbacks current.result = callback(current.result, *args, **kw) --- <excepti -- TRACEBACK ELIDED -- banana.py", line 215, in produce slicer = self.newSlicerFor(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/banana.py", line 314, in newSlicerFor return topSlicer.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 48, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicer.py", line 126, in slicerForObject return self.parent.slicerForObject(obj) File "/usr/local/lib/python2.7/dist-packages/foolscap/slicers/root.py", line 66, in slicerForObject raise Violation("cannot serialize %s (%s)" % (obj, name)) foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0]-of-msg>.??.??): ("cannot serialize The '[drop_upload] local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",) ] ```
zooko commented 2015-08-14 21:25:51 +00:00
Author
Copy Link

I then started a flogtool tail going with this command: tahoe debug flogtool tail --verbose --save-to=flog-tail.flog --timestamps=utc ~/.tahoe/private/logport.furl, and then I re-ran the exact same tahoe backup command, like this: time tahoe backup -v -v -v . papers:. This time the tail of the output of the tahoe backup command was this:

skipping '/papers/incoming-on-sparkn/Morris et al. 2014 - Is Alzheimerʼs Disease a Systemic Disease.pdf'..
skipping '/papers/incoming-on-sparkn/UKPDS - low fat, high fibre doesnʼt work.pdf'..
skipping '/papers/incoming-on-sparkn/Medical Hypotheses Volume 76 issue 2 2011 [doi 10.1016%2Fj.mehy.2010.09.006] Edward Henry Mathews; Leon Liebenberg; Ruaan Pelzer -- High-glycolytic cancers and their interplay with the bodyʼs glucose demand and supply cycl-1.pdf'..
skipping '/papers/incoming-on-sparkn/Medical Hypotheses Volume 76 issue 2 2011 [doi 10.1016%2Fj.mehy.2010.09.006] Edward Henry Mathews; Leon Liebenberg; Ruaan Pelzer -- High-glycolytic cancers and their interplay with the bodyʼs glucose demand and supply cycl.pdf'..
skipping '/papers/incoming-on-sparkn/1993y Riordan Treatment of active Crohnʼs disease by exclusion diet - East Anglian Multicentre Controlled Trial.pdf'..
skipping '/papers/incoming-on-sparkn/Swerdlow - Mitochondrial Manipulation and the Quest for Alzheimerʼs Treatments.pdf'..
skipping '/papers/incoming-on-sparkn/Bredesen-2014-“Reversal of cognitive decline: A novel therapeutic program”.pdf'..
skipping '/papers/incoming-on-sparkn/ioi150059.pdf'..
skipping '/papers/incoming-on-sparkn/Poff-2015-“Non-Toxic Metabolic Management of Metastatic Cancer in VM Mice: Novel Combination of Ketogenic Diet, Ketone Supplementation, and Hyperbaric Oxygen Therapy”.pdf'..
skipping '/papers/incoming-on-sparkn/what-must-i-do-to-get-well-by-elma-stuart.pdf'..
skipping '/papers/incoming-on-sparkn/sullivan2015(1).pdf'..
skipping '/papers/incoming-on-sparkn/cai2015.pdf'..
skipping '/papers/incoming-on-sparkn/10.1038@nn.3922.pdf'..
skipping '/papers/incoming-on-sparkn/JCI6223(1).pdf'..
skipping '/papers/incoming-on-sparkn/Onodera-2014-“Increased sugar uptake promotes oncogenesis via EPAC⁄RAP1 and O-GlcNAc pathways”.pdf'..
skipping '/papers/incoming-on-sparkn/Reaven-2003-“Insulin Resistance and Compensatory Hyperinsulinemia — The Key Player Between Cigarette Smoking and Cardiovascular Disease?”.pdf'..
skipping '/papers/incoming-on-sparkn/Nebeling-1992-“Effects of dietary-induced ketosis on tumor metabolism, nutritional status, and quality of life in pediatric oncology patients (dissertation)”.pdf'..
skipping '/papers/incoming-on-sparkn/Poff-2014-“Ketone supplementation decreases tumor cell viability and prolongs survival of mice with metastatic cancer”.pdf'..
skipping '/papers/incoming-on-sparkn/Wang-2015-“Hyperbaric oxygen promotes malignant glioma cell growth and inhibits cell apoptosis”.pdf'..
 re-using old directory for '/papers/incoming-on-sparkn'
 re-using old directory for '/papers'
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 160, in run
    rc = runner(sys.argv[1:], install_node_control=install_node_control)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 145, in runner
    rc = cli.dispatch[command](so)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/cli.py", line 543, in backup
    rc = tahoe_backup.backup(options)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 326, in backup
    return bu.run()
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 123, in run
    put_child(archives_url, now, new_backup_dircap)
  File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 57, in put_child
    raise HTTPError("Error during put_child", resp)
HTTPError: Error during put_child: 410 Gone
UnrecoverableFileError: the directory (or mutable file) could not be retrieved, because there were insufficient good shares. This might indicate that no servers were connected, insufficient servers were connected, the URI was corrupt, or that shares have been lost due to server departure, hard drive failure, or disk corruption. You should perform a filecheck on this object to learn more.

real    0m1.996s
user    0m1.378s
sys     0m0.275s

And the resulting flog tail file (which I will attach to this ticket), dumps to this:

Application versions (embedded in logfile):
           Nevow: 0.11.1
         OpenSSL: 1.0.1f
         Twisted: 15.0.0
 allmydata-tahoe: 1.10.1
  characteristic: 14.3.0
        foolscap: 0.8.0
            mock: 1.0.1
        platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF
       pyOpenSSL: 0.13
          pyasn1: 0.1.7
  pyasn1-modules: 0.0.5
        pycrypto: 2.6.1
      pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958
          python: 2.7.6
service-identity: 14.0.0
      setuptools: 3.3
      simplejson: 3.3.1
         twisted: 15.0.0
            zfec: 1.4.24
  zope.interface: unknown
PID: 18820

gzi2nwh4#1903 2015-08-14_21:24:28.339945Z: SharemapUpdater(ia2sk): starting (MODE_READ)
gzi2nwh4#1904 2015-08-14_21:24:28.340042Z: sending query to [6dwd2q], readsize=4000
gzi2nwh4#1905 2015-08-14_21:24:28.505961Z: got result from [6dwd2q], 0 shares
gzi2nwh4#1906 2015-08-14_21:24:28.506059Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#1907 2015-08-14_21:24:28.506081Z: all queries are retired, no extra servers: done
gzi2nwh4#1908 2015-08-14_21:24:28.506105Z: servermap: 
gzi2nwh4#1909 2015-08-14_21:24:28.506130Z: _got_results done
gzi2nwh4#1910 2015-08-14_21:24:28.506159Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#1911 2015-08-14_21:24:28.506174Z: but we're not running
gzi2nwh4#1912 2015-08-14_21:24:28.516350Z: web: 127.0.0.1 GET /uri/[CENSORED]..?t=json 410 390
gzi2nwh4#1913 2015-08-14_21:24:29.706012Z: SharemapUpdater(ia2sk): starting (MODE_READ)
gzi2nwh4#1914 2015-08-14_21:24:29.706408Z: sending query to [6dwd2q], readsize=4000
gzi2nwh4#1915 2015-08-14_21:24:29.819582Z: got result from [6dwd2q], 0 shares
gzi2nwh4#1916 2015-08-14_21:24:29.819817Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#1917 2015-08-14_21:24:29.819844Z: all queries are retired, no extra servers: done
gzi2nwh4#1918 2015-08-14_21:24:29.819874Z: servermap: 
gzi2nwh4#1919 2015-08-14_21:24:29.819904Z: _got_results done
gzi2nwh4#1920 2015-08-14_21:24:29.819935Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False
gzi2nwh4#1921 2015-08-14_21:24:29.819952Z: but we're not running
gzi2nwh4#1922 2015-08-14_21:24:29.830873Z: web: 127.0.0.1 PUT /uri/[CENSORED]..?t=uri 410 390

Note, that's the complete output of the dump — only 43 lines.

I then started a flogtool tail going with this command: `tahoe debug flogtool tail --verbose --save-to=flog-tail.flog --timestamps=utc ~/.tahoe/private/logport.furl`, and then I re-ran the exact same `tahoe backup` command, like this: `time tahoe backup -v -v -v . papers:`. This time the tail of the output of the `tahoe backup` command was this: ``` skipping '/papers/incoming-on-sparkn/Morris et al. 2014 - Is Alzheimerʼs Disease a Systemic Disease.pdf'.. skipping '/papers/incoming-on-sparkn/UKPDS - low fat, high fibre doesnʼt work.pdf'.. skipping '/papers/incoming-on-sparkn/Medical Hypotheses Volume 76 issue 2 2011 [doi 10.1016%2Fj.mehy.2010.09.006] Edward Henry Mathews; Leon Liebenberg; Ruaan Pelzer -- High-glycolytic cancers and their interplay with the bodyʼs glucose demand and supply cycl-1.pdf'.. skipping '/papers/incoming-on-sparkn/Medical Hypotheses Volume 76 issue 2 2011 [doi 10.1016%2Fj.mehy.2010.09.006] Edward Henry Mathews; Leon Liebenberg; Ruaan Pelzer -- High-glycolytic cancers and their interplay with the bodyʼs glucose demand and supply cycl.pdf'.. skipping '/papers/incoming-on-sparkn/1993y Riordan Treatment of active Crohnʼs disease by exclusion diet - East Anglian Multicentre Controlled Trial.pdf'.. skipping '/papers/incoming-on-sparkn/Swerdlow - Mitochondrial Manipulation and the Quest for Alzheimerʼs Treatments.pdf'.. skipping '/papers/incoming-on-sparkn/Bredesen-2014-“Reversal of cognitive decline: A novel therapeutic program”.pdf'.. skipping '/papers/incoming-on-sparkn/ioi150059.pdf'.. skipping '/papers/incoming-on-sparkn/Poff-2015-“Non-Toxic Metabolic Management of Metastatic Cancer in VM Mice: Novel Combination of Ketogenic Diet, Ketone Supplementation, and Hyperbaric Oxygen Therapy”.pdf'.. skipping '/papers/incoming-on-sparkn/what-must-i-do-to-get-well-by-elma-stuart.pdf'.. skipping '/papers/incoming-on-sparkn/sullivan2015(1).pdf'.. skipping '/papers/incoming-on-sparkn/cai2015.pdf'.. skipping '/papers/incoming-on-sparkn/10.1038@nn.3922.pdf'.. skipping '/papers/incoming-on-sparkn/JCI6223(1).pdf'.. skipping '/papers/incoming-on-sparkn/Onodera-2014-“Increased sugar uptake promotes oncogenesis via EPAC⁄RAP1 and O-GlcNAc pathways”.pdf'.. skipping '/papers/incoming-on-sparkn/Reaven-2003-“Insulin Resistance and Compensatory Hyperinsulinemia — The Key Player Between Cigarette Smoking and Cardiovascular Disease?”.pdf'.. skipping '/papers/incoming-on-sparkn/Nebeling-1992-“Effects of dietary-induced ketosis on tumor metabolism, nutritional status, and quality of life in pediatric oncology patients (dissertation)”.pdf'.. skipping '/papers/incoming-on-sparkn/Poff-2014-“Ketone supplementation decreases tumor cell viability and prolongs survival of mice with metastatic cancer”.pdf'.. skipping '/papers/incoming-on-sparkn/Wang-2015-“Hyperbaric oxygen promotes malignant glioma cell growth and inhibits cell apoptosis”.pdf'.. re-using old directory for '/papers/incoming-on-sparkn' re-using old directory for '/papers' Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 160, in run rc = runner(sys.argv[1:], install_node_control=install_node_control) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/runner.py", line 145, in runner rc = cli.dispatch[command](so) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/cli.py", line 543, in backup rc = tahoe_backup.backup(options) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 326, in backup return bu.run() File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 123, in run put_child(archives_url, now, new_backup_dircap) File "/usr/local/lib/python2.7/dist-packages/allmydata/scripts/tahoe_backup.py", line 57, in put_child raise HTTPError("Error during put_child", resp) HTTPError: Error during put_child: 410 Gone UnrecoverableFileError: the directory (or mutable file) could not be retrieved, because there were insufficient good shares. This might indicate that no servers were connected, insufficient servers were connected, the URI was corrupt, or that shares have been lost due to server departure, hard drive failure, or disk corruption. You should perform a filecheck on this object to learn more. real 0m1.996s user 0m1.378s sys 0m0.275s ``` And the resulting flog tail file (which I will attach to this ticket), dumps to this: ``` Application versions (embedded in logfile): Nevow: 0.11.1 OpenSSL: 1.0.1f Twisted: 15.0.0 allmydata-tahoe: 1.10.1 characteristic: 14.3.0 foolscap: 0.8.0 mock: 1.0.1 platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF pyOpenSSL: 0.13 pyasn1: 0.1.7 pyasn1-modules: 0.0.5 pycrypto: 2.6.1 pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958 python: 2.7.6 service-identity: 14.0.0 setuptools: 3.3 simplejson: 3.3.1 twisted: 15.0.0 zfec: 1.4.24 zope.interface: unknown PID: 18820 gzi2nwh4#1903 2015-08-14_21:24:28.339945Z: SharemapUpdater(ia2sk): starting (MODE_READ) gzi2nwh4#1904 2015-08-14_21:24:28.340042Z: sending query to [6dwd2q], readsize=4000 gzi2nwh4#1905 2015-08-14_21:24:28.505961Z: got result from [6dwd2q], 0 shares gzi2nwh4#1906 2015-08-14_21:24:28.506059Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#1907 2015-08-14_21:24:28.506081Z: all queries are retired, no extra servers: done gzi2nwh4#1908 2015-08-14_21:24:28.506105Z: servermap: gzi2nwh4#1909 2015-08-14_21:24:28.506130Z: _got_results done gzi2nwh4#1910 2015-08-14_21:24:28.506159Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#1911 2015-08-14_21:24:28.506174Z: but we're not running gzi2nwh4#1912 2015-08-14_21:24:28.516350Z: web: 127.0.0.1 GET /uri/[CENSORED]..?t=json 410 390 gzi2nwh4#1913 2015-08-14_21:24:29.706012Z: SharemapUpdater(ia2sk): starting (MODE_READ) gzi2nwh4#1914 2015-08-14_21:24:29.706408Z: sending query to [6dwd2q], readsize=4000 gzi2nwh4#1915 2015-08-14_21:24:29.819582Z: got result from [6dwd2q], 0 shares gzi2nwh4#1916 2015-08-14_21:24:29.819817Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#1917 2015-08-14_21:24:29.819844Z: all queries are retired, no extra servers: done gzi2nwh4#1918 2015-08-14_21:24:29.819874Z: servermap: gzi2nwh4#1919 2015-08-14_21:24:29.819904Z: _got_results done gzi2nwh4#1920 2015-08-14_21:24:29.819935Z: _check_for_done, mode is 'MODE_READ', 0 queries outstanding, 0 extra servers available, 0 'must query' servers left, need_privkey=False gzi2nwh4#1921 2015-08-14_21:24:29.819952Z: but we're not running gzi2nwh4#1922 2015-08-14_21:24:29.830873Z: web: 127.0.0.1 PUT /uri/[CENSORED]..?t=uri 410 390 ``` Note, that's the *complete* output of the dump — only 43 lines.
zooko commented 2015-08-14 21:26:19 +00:00
Author
Copy Link

Attachment flog-tail-2.flog (8991 bytes) added

**Attachment** flog-tail-2.flog (8991 bytes) added
flog-tail-2.flog
8.8 KiB
zooko commented 2015-08-14 21:28:18 +00:00
Author
Copy Link

I clicked the "report an incident" button and it generated incident-2015-08-14--21-27-34Z-tvkqqwy.flog.bz2

I clicked the "report an incident" button and it generated `incident-2015-08-14--21-27-34Z-tvkqqwy.flog.bz2`
zooko commented 2015-08-14 21:29:07 +00:00
Author
Copy Link

Attachment incident-2015-08-14--21-27-34Z-tvkqqwy.flog.bz2 (17621 bytes) added

**Attachment** incident-2015-08-14--21-27-34Z-tvkqqwy.flog.bz2 (17621 bytes) added
incident-2015-08-14--21-27-34Z-tvkqqwy.flog.bz2
17 KiB
zooko commented 2015-08-14 21:55:44 +00:00
Author
Copy Link

I updated to current git HEAD and re-ran the test and got the same result. tahoe version now says:

allmydata-tahoe: 1.10.1a1.post66.dev0 [master: 7309aed524f3bc44ec4035d35556118eea6416ba-dirty]
foolscap: 0.8.0
pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958
zfec: 1.4.24
Twisted: 15.0.0
Nevow: 0.11.1
zope.interface: unknown
python: 2.7.6
platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF
pyOpenSSL: 0.13
OpenSSL: 1.0.1f [6 Jan 2014]
simplejson: 3.3.1
pycrypto: 2.6.1
pyasn1: 0.1.8
service-identity: 14.0.0
characteristic: 14.3.0
pyasn1-modules: 0.0.5
setuptools: 3.3
I updated to current git HEAD and re-ran the test and got the same result. `tahoe version` now says: ``` allmydata-tahoe: 1.10.1a1.post66.dev0 [master: 7309aed524f3bc44ec4035d35556118eea6416ba-dirty] foolscap: 0.8.0 pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958 zfec: 1.4.24 Twisted: 15.0.0 Nevow: 0.11.1 zope.interface: unknown python: 2.7.6 platform: Linux-Ubuntu_14.04-x86_64-64bit_ELF pyOpenSSL: 0.13 OpenSSL: 1.0.1f [6 Jan 2014] simplejson: 3.3.1 pycrypto: 2.6.1 pyasn1: 0.1.8 service-identity: 14.0.0 characteristic: 14.3.0 pyasn1-modules: 0.0.5 setuptools: 3.3 ```
zooko commented 2015-08-14 21:59:43 +00:00
Author
Copy Link

Then I tried a deep-check. The stdout was:

zooko@spark /papers $ time tahoe deep-check --verbose --verify papers:
'<root>': Unhealthy: no versions are recoverable
ERROR: UnrecoverableFileError(no recoverable versions)
"[Failure instance: Traceback: <class 'allmydata.mutable.common.UnrecoverableFileError'>: no recoverable versions"
/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/base.py:824:runUntilCurrent
/usr/local/lib/python2.7/dist-packages/foolscap/eventual.py:26:_turn
/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py:383:callback
/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py:491:_startRunCallbacks
--- <exception caught here> ---
/usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py:578:_runCallbacks
/usr/local/lib/python2.7/dist-packages/allmydata_tahoe-1.10.1a1.post66.dev0-py2.7.egg/allmydata/mutable/filenode.py:400:_get_version

real    0m0.743s
user    0m0.392s
sys     0m0.080s

I'll attach the flog tail and the incident report file that I generated by the "report an incident" button.

Then I tried a `deep-check`. The stdout was: ``` zooko@spark /papers $ time tahoe deep-check --verbose --verify papers: '<root>': Unhealthy: no versions are recoverable ERROR: UnrecoverableFileError(no recoverable versions) "[Failure instance: Traceback: <class 'allmydata.mutable.common.UnrecoverableFileError'>: no recoverable versions" /usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/base.py:824:runUntilCurrent /usr/local/lib/python2.7/dist-packages/foolscap/eventual.py:26:_turn /usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py:383:callback /usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py:491:_startRunCallbacks --- <exception caught here> --- /usr/local/lib/python2.7/dist-packages/Twisted-15.0.0-py2.7-linux-x86_64.egg/twisted/internet/defer.py:578:_runCallbacks /usr/local/lib/python2.7/dist-packages/allmydata_tahoe-1.10.1a1.post66.dev0-py2.7.egg/allmydata/mutable/filenode.py:400:_get_version real 0m0.743s user 0m0.392s sys 0m0.080s ``` I'll attach the flog tail and the incident report file that I generated by the "report an incident" button.
zooko commented 2015-08-14 22:00:10 +00:00
Author
Copy Link

Attachment incident-2015-08-14--21-58-50Z-oxrfsra.flog.bz2 (10087 bytes) added

**Attachment** incident-2015-08-14--21-58-50Z-oxrfsra.flog.bz2 (10087 bytes) added
incident-2015-08-14--21-58-50Z-oxrfsra.flog.bz2
9.9 KiB
zooko commented 2015-08-14 22:00:29 +00:00
Author
Copy Link

Attachment flog-tail-5.flog (8476 bytes) added

**Attachment** flog-tail-5.flog (8476 bytes) added
flog-tail-5.flog
8.3 KiB
zooko commented 2015-08-14 22:02:24 +00:00
Author
Copy Link

I used tahoe debug dump-cap to get more information about the root directory which is the one that is unrecoverable according to that deep-check output from comment:98060:

 storage index: ia2sk372zlgrf5o6s3pet44wii
 fingerprint: xtac4ubcnr5eqo6d7h4wyj5sm522olj4mthizz2i3lfw2b5nla6q
I used `tahoe debug dump-cap` to get more information about the root directory which is the one that is unrecoverable according to that deep-check output from [comment:98060](/tahoe-lafs/trac-2024-07-25/issues/2482#issuecomment-98060): ``` storage index: ia2sk372zlgrf5o6s3pet44wii fingerprint: xtac4ubcnr5eqo6d7h4wyj5sm522olj4mthizz2i3lfw2b5nla6q ```
daira commented 2015-08-17 14:46:42 +00:00
Owner
Copy Link
     raise Violation("cannot serialize %s (%s)" % (obj, name))
 foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0
 ]-of-msg>.??.??): ("cannot serialize The 'drop_upload local.directory'
 parameter was '/home/zooko/drop_upload' but there is no directory at that
 location. (<type 'exceptions.AssertionError'>)",)

Is drop_upload enabled set to true in tahoe.cfg? Try setting it to false. (This might be unrelated to the backup error, but I want to eliminate it from consideration if so.)

``` raise Violation("cannot serialize %s (%s)" % (obj, name)) foolscap.tokens.Violation: Violation (<RootSlicer>.<call-0-1-msg>.<arg[0 ]-of-msg>.??.??): ("cannot serialize The 'drop_upload local.directory' parameter was '/home/zooko/drop_upload' but there is no directory at that location. (<type 'exceptions.AssertionError'>)",) ``` Is `drop_upload enabled` set to true in `tahoe.cfg`? Try setting it to false. (This might be unrelated to the backup error, but I want to eliminate it from consideration if so.)
zooko commented 2015-08-21 16:19:30 +00:00
Author
Copy Link

I unset that setting and reproduced the issue — same behavior after drop upload was disabled.

I unset that setting and reproduced the issue — same behavior after drop upload was disabled.
daira commented 2015-08-25 17:42:19 +00:00
Owner
Copy Link

This was due to Zooko's TLoS3 subscription having been cancelled.

This was due to Zooko's TLoS3 subscription having been cancelled.
tahoe-lafs added the
invalid
 label 2015-08-25 17:42:19 +00:00
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels   
0.2.0

   
0.3.0

   
0.4.0

   
0.5.0

   
0.5.1

   
0.6.0

   
0.6.1

   
0.7.0

   
0.8.0

   
0.9.0

   
1.0.0

   
1.1.0

   
1.10.0

   
1.10.1

   
1.10.2

   
1.10a2

   
1.11.0

   
1.12.0

   
1.12.1

   
1.13.0

   
1.14.0

   
1.15.0

   
1.15.1

   
1.2.0

   
1.3.0

   
1.4.1

   
1.5.0

   
1.6.0

   
1.6.1

   
1.7.0

   
1.7.1

   
1.7β

   
1.8.0

   
1.8.1

   
1.8.2

   
1.8.3

   
1.8β

   
1.9.0

   
1.9.0-s3branch

   
1.9.0a1

   
1.9.0a2

   
1.9.0b1

   
1.9.1

   
1.9.2

   
1.9.2a1

   
LeastAuthority.com automation

   
blocker

   
cannot reproduce

   
cloud-branch

   
code

catch-all for anything that can be fixed by writing code but isn't classified better

  
code-dirnodes

anything involving tahoe directories

  
code-encoding

immutable-file encoding format/layout, cap format, encoding/decoding algorithms

  
code-frontend

general frontend things: new user-facing interfaces, FTP/SFTP servers, FUSE-like interfaces

  
code-frontend-cli

CLI tools

  
code-frontend-ftp-sftp

   
code-frontend-magic-folder

   
code-frontend-web

webapi interfaces, user-facing "WUI" interfaces

  
code-mutable

anything involving mutable files: encoding/decoding, share format

  
code-network

Introducer, locating storage servers, establishing/maintaining connections to them

  
code-nodeadmin

node startup/shutdown, tools to create nodes, logging tools, management/monitoring tools, manhole, disk-space-limiting tools

  
code-peerselection

server selection/sorting algorithm, rebalancing code, allocation policy, swarming-download

  
code-storage

storage-server implementation, share-storage directory layout, client-to-server share transfer protocol

  
contrib

problems with non-core things that live in the source:contrib/ directory

  
critical

   
defect

   
dev-infrastructure

things that help us build Tahoe: buildbot, automated speed/memory/code-coverage tests and results-displayers, IRC channels, mailing lists, this Trac instance

  
documentation

docs items. Also use 'docs' keyword on tickets in more specific components.

  
duplicate

   
enhancement

   
fixed

   
invalid

   
major

   
minor

   
n/a

   
normal

   
operational

things involved in running a tahoe grid, external tools to monitor/maintain a grid (like "nodeadmin" but larger-scale). Was also used for issues with the allmydata.com grid.

  
packaging

setup.py script, library dependencies, binary packages, licensing, installation instructions

  
somebody else's problem

   
supercritical

   
task

   
trivial

   
unknown

Uncategorized. All tickets default to this component until someone updates it.

  
was already fixed

   
website

things about the tahoe-lafs.org website (and sometimes this Trac instance, shared with 'dev-infrastructure')

  
wontfix

   
worksforme
No Label
0.2.0
0.3.0
0.4.0
0.5.0
0.5.1
0.6.0
0.6.1
0.7.0
0.8.0
0.9.0
1.0.0
1.1.0
1.10.0
1.10.1
1.10.2
1.10a2
1.11.0
1.12.0
1.12.1
1.13.0
1.14.0
1.15.0
1.15.1
1.2.0
1.3.0
1.4.1
1.5.0
1.6.0
1.6.1
1.7.0
1.7.1
1.7β
1.8.0
1.8.1
1.8.2
1.8.3
1.8β
1.9.0
1.9.0-s3branch
1.9.0a1
1.9.0a2
1.9.0b1
1.9.1
1.9.2
1.9.2a1
LeastAuthority.com automation
blocker
cannot reproduce
cloud-branch
code
code-dirnodes
code-encoding
code-frontend
code-frontend-cli
code-frontend-ftp-sftp
code-frontend-magic-folder
code-frontend-web
code-mutable
code-network
code-nodeadmin
code-peerselection
code-storage
contrib
critical
defect
dev-infrastructure
documentation
duplicate
enhancement
fixed
invalid
major
minor
n/a
normal
operational
packaging
somebody else's problem
supercritical
task
trivial
unknown
was already fixed
website
wontfix
worksforme
Milestone
Clear milestone
No items
No Milestone
undecided
Assignees
Clear assignees
No Assignees
2 Participants
Notifications
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Reference: tahoe-lafs/trac-2024-07-25#2482
No description provided.
Delete Branch "%!s(<nil>)"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?