Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

IPNS: context deadline exceeded #7244

Closed
ligi opened this issue Apr 28, 2020 · 17 comments · Fixed by #7256
Closed

IPNS: context deadline exceeded #7244

ligi opened this issue Apr 28, 2020 · 17 comments · Fixed by #7256
Assignees
Labels
kind/bug A bug in existing code (including security flaws) need/triage Needs initial labeling and prioritization

Comments

@ligi
Copy link

ligi commented Apr 28, 2020

I was excited to read that 0.5 speeds up IPNS. So I wanted to give it a spin. Unfortunately I get an error now:

ligi@komputing:~$ ipfs add -Q -r /opt/source-verify/production/source-verify/repository/
QmfXZmzSaEZvEWrJtTjJkmXDV5Dpoxz2diHFPHvnsrexa3
ligi@komputing:~$ ipfs name publish QmfXZmzSaEZvEWrJtTjJkmXDV5Dpoxz2diHFPHvnsrexa3
Error: context deadline exceeded

running this version:

go-ipfs version: 0.5.0
Repo version: 9
System version: amd64/linux
Golang version: go1.13.10

@ligi ligi added kind/bug A bug in existing code (including security flaws) need/triage Needs initial labeling and prioritization labels Apr 28, 2020
@aschmahmann
Copy link
Contributor

aschmahmann commented Apr 28, 2020

@ligi there are a number of IPNS related improvements in the 0.5 release. However, IPNS Publishing (like IPFS Providing) on the DHT will still not be as fast as indicated by testing until more of the network upgrades (for posterity this issue was filed on day one of the release).

Even on day one of the release publishing IPNS records should still be faster than in 0.4.23 and earlier though.

@ligi
Copy link
Author

ligi commented Apr 28, 2020

@aschmahmann thanks for the info - advocating the migration to 0.5.0 even more then ;-)
btw.: can I increase the context deadline somehow?

@aschmahmann
Copy link
Contributor

@ligi at first glance it doesn't look like there is, but that seems like something you should be able to do. Thanks for the bug report 😄.

@ligi ligi changed the title IPNS: context deatline exceeded IPNS: context deadline exceeded Apr 28, 2020
@ligi
Copy link
Author

ligi commented Apr 28, 2020

My pleasure - thanks for your work!

@santhoshtr
Copy link

Upgraded to 0.5.0 and facing the same issue when running publish using http api

TimeoutError: context deadline exceeded
    at Object.errorHandler [as handleError] (/home/santhosh/work/exp/ipfs/node_modules/ipfs-http-client/src/lib/core.js:71:13)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (internal/process/task_queues.js:97:5)
    at async Client.fetch (/home/santhosh/work/exp/ipfs/node_modules/ipfs-utils/src/http.js:145:9)
    at async Object.publish (/home/santhosh/work/exp/ipfs/node_modules/ipfs-http-client/src/name/publish.js:9:17)

@xmaysonnave
Copy link

xmaysonnave commented Apr 29, 2020

Dear Friends,

I'm facing the same issue than @santhoshtr
However from my understanding I noticed the following behaviour.
Even this exception is raised the update is successfully published on my local IPFS server.
I understand that this issue is related to the fact that my local dev server is behind a NAT/Firewall.
I also understand that remote peers will no get the update at this point.

However I'm wondering if at some point the server will try again by itself to publish the IPNS update. Let's say that this local server at some point is exposed to its peers through a public IP address. What happened then ???

The ultimate concern is the way I need to handle this issue in my DApp. Warning or errors as the update is available locally. Currently as the update is available locally I consider it as warning (bit will it be published to remote peers later ??)

Hope its clear.

Thanks

@vrde
Copy link

vrde commented Apr 29, 2020

[crossposting from twitter]
I tried to publish the cid @ligi posted and I got the same error on v0.5.0:

➜  ~ ipfs name publish QmfXZmzSaEZvEWrJtTjJkmXDV5Dpoxz2diHFPHvnsrexa3
Error: context deadline exceeded

@sinkuu
Copy link
Contributor

sinkuu commented Apr 29, 2020

When I encounter this problem, the daemon logs a "error when determining the last published IPNS record" (using ipfs log level namesys debug). It would be nice if CLI client shows that message in addition to the obscure "context deadline exceeded".

Apr 29 20:11:19 localhost ipfs[342]: 2020-04-29T20:11:19.383+0900        DEBUG        namesys        namesys/publisher.go:126        error when determining the last published IPNS record for Qmak3N3ey6AAGndq5zwZD3N2oP5gJkS4A8QGEqVUR7J7gT: context deadline exceeded
Apr 29 20:11:19 localhost ipfs[342]: [153B blob data]
Apr 29 20:11:19 localhost ipfs[342]: [159B blob data]

@aschmahmann
Copy link
Contributor

@sinkuu the error returned isn't actually from error when determining the last published IPNS record since if you look at that line in publisher.go it returns no error, just a debug log.

What is happening instead is that the Publish part has been hard coded to have a 1 minute timeout https://github.com/ipfs/go-ipfs/blob/36789eaa88a7277c06a22b7955f128409c705746/namesys/publisher.go#L277-L278 and that seems unfortunate since the user should be able to let the query go longer than that if they want.

@achingbrain
Copy link
Member

achingbrain commented Apr 29, 2020

It would be really helpful if that timeout was configurable, either globally or as a command option - we'd be able to shave a few minutes off an interop test run as they spend a long time doing nothing while they wait for the timeouts to expire.

@Stebalien
Copy link
Member

Let's remove that timeout for now.

@xmaysonnave
Copy link

#7256 (comment)

@aschmahmann
Copy link
Contributor

For anyone coming to this issue in between v0.5.0 and v0.5.1 here's the summary:

Sometime IPNS publishing takes over a minute and times out giving you the error "context deadline exceeded", this one minute timeout has been removed and will be part of the next patch release.

Note: As of today (about a week after the release) IPNS publishes normally finish in less than a minute (I get about 30 seconds). However, there are DHT lookups that take longer than a minute. Trying again frequently works. As more of the network adopts v0.5.0 the network will improve and lookup times for IPNS should improve.

Stebalien added a commit that referenced this issue May 9, 2020
Hot on the heels of 0.5.0 is 0.5.1 with some important but small bug fixes. This release:

1. Removes the 1 minute timeout for IPNS publishes (fixes #7244).
2. Backport a DHT fix to reduce CPU usage for canceled requests.
3. Fixes some timer leaks in the QUIC transport ([#2515](quic-go/quic-go#2515)).

Full changelog:

- github.com/ipfs/go-ipfs:
  - IPNS timeout patch from master ([#7276](#7276))
- github.com/libp2p/go-libp2p-core (v0.5.2 -> v0.5.3):
  - feat: add a function to tell if a context subscribes to query events ([libp2p/go-libp2p-core#147](libp2p/go-libp2p-core#147))
- github.com/libp2p/go-libp2p-kad-dht (v0.7.10 -> v0.7.11):
  - fix: optimize for the case where we're not subscribing to query events ([libp2p/go-libp2p-kad-dht#624](libp2p/go-libp2p-kad-dht#624))
  - fix: don't spin when the event channel is closed ([libp2p/go-libp2p-kad-dht#622](libp2p/go-libp2p-kad-dht#622))
- github.com/libp2p/go-libp2p-routing-helpers (v0.2.2 -> v0.2.3):
  - fix: avoid subscribing to query events unless necessary ([libp2p/go-libp2p-routing-helpers#43](libp2p/go-libp2p-routing-helpers#43))
- github.com/lucas-clemente/quic-go (v0.15.5 -> v0.15.7):
  - reset the PTO when dropping a packet number space
  - move deadlineTimer declaration out of the Read loop
  - stop the deadline timer in Stream.Read and Write
  - fix buffer use after it was released when sending an INVALID_TOKEN error
  - create the session timer at the beginning of the run loop
  - stop the timer when the session's run loop returns
@RubenKelevra
Copy link
Contributor

It would be really helpful if that timeout was configurable, either globally or as a command option - we'd be able to shave a few minutes off an interop test run as they spend a long time doing nothing while they wait for the timeouts to expire.

The timeout is configurable:

[ruben@i3 ~]$ time ipfs --api="/ip6/::1/tcp/5001" name publish --timeout=1s --key="test" bafybeihtwu6nkwgidugswmwwvsqqukl7cmhf6ne5f3cqi2ocedsbjmmvfe
Error: context deadline exceeded

real    0m1,044s
user    0m0,031s
sys     0m0,030s
[ruben@i3 ~]$ time ipfs --api="/ip6/::1/tcp/5001" name publish --timeout=5s --key="test" bafybeihtwu6nkwgidugswmwwvsqqukl7cmhf6ne5f3cqi2ocedsbjmmvfe
Error: context deadline exceeded

real    0m5,044s
user    0m0,028s
sys     0m0,033s

@achingbrain
Copy link
Member

The --timeout option is a global cli option that makes the operation return a non-zero exit code after the specified timeout.

This is not the timeout I'm referring to, I'm talking about the one Adin mentions:

What is happening instead is that the Publish part has been hard coded to have a 1 minute timeout

Sorry if that's wasn't clear.

@Stebalien
Copy link
Member

This timeout has been removed in 0.5.1.

@hacdias hacdias unpinned this issue May 11, 2020
ralendor pushed a commit to ralendor/go-ipfs that referenced this issue Jun 6, 2020
Hot on the heels of 0.5.0 is 0.5.1 with some important but small bug fixes. This release:

1. Removes the 1 minute timeout for IPNS publishes (fixes ipfs#7244).
2. Backport a DHT fix to reduce CPU usage for canceled requests.
3. Fixes some timer leaks in the QUIC transport ([ipfs#2515](quic-go/quic-go#2515)).

Full changelog:

- github.com/ipfs/go-ipfs:
  - IPNS timeout patch from master ([ipfs#7276](ipfs#7276))
- github.com/libp2p/go-libp2p-core (v0.5.2 -> v0.5.3):
  - feat: add a function to tell if a context subscribes to query events ([libp2p/go-libp2p-core#147](libp2p/go-libp2p-core#147))
- github.com/libp2p/go-libp2p-kad-dht (v0.7.10 -> v0.7.11):
  - fix: optimize for the case where we're not subscribing to query events ([libp2p/go-libp2p-kad-dht#624](libp2p/go-libp2p-kad-dht#624))
  - fix: don't spin when the event channel is closed ([libp2p/go-libp2p-kad-dht#622](libp2p/go-libp2p-kad-dht#622))
- github.com/libp2p/go-libp2p-routing-helpers (v0.2.2 -> v0.2.3):
  - fix: avoid subscribing to query events unless necessary ([libp2p/go-libp2p-routing-helpers#43](libp2p/go-libp2p-routing-helpers#43))
- github.com/lucas-clemente/quic-go (v0.15.5 -> v0.15.7):
  - reset the PTO when dropping a packet number space
  - move deadlineTimer declaration out of the Read loop
  - stop the deadline timer in Stream.Read and Write
  - fix buffer use after it was released when sending an INVALID_TOKEN error
  - create the session timer at the beginning of the run loop
  - stop the timer when the session's run loop returns
ralendor pushed a commit to ralendor/go-ipfs that referenced this issue Jun 6, 2020
Hot on the heels of 0.5.0 is 0.5.1 with some important but small bug fixes. This release:

1. Removes the 1 minute timeout for IPNS publishes (fixes ipfs#7244).
2. Backport a DHT fix to reduce CPU usage for canceled requests.
3. Fixes some timer leaks in the QUIC transport ([ipfs#2515](quic-go/quic-go#2515)).

Full changelog:

- github.com/ipfs/go-ipfs:
  - IPNS timeout patch from master ([ipfs#7276](ipfs#7276))
- github.com/libp2p/go-libp2p-core (v0.5.2 -> v0.5.3):
  - feat: add a function to tell if a context subscribes to query events ([libp2p/go-libp2p-core#147](libp2p/go-libp2p-core#147))
- github.com/libp2p/go-libp2p-kad-dht (v0.7.10 -> v0.7.11):
  - fix: optimize for the case where we're not subscribing to query events ([libp2p/go-libp2p-kad-dht#624](libp2p/go-libp2p-kad-dht#624))
  - fix: don't spin when the event channel is closed ([libp2p/go-libp2p-kad-dht#622](libp2p/go-libp2p-kad-dht#622))
- github.com/libp2p/go-libp2p-routing-helpers (v0.2.2 -> v0.2.3):
  - fix: avoid subscribing to query events unless necessary ([libp2p/go-libp2p-routing-helpers#43](libp2p/go-libp2p-routing-helpers#43))
- github.com/lucas-clemente/quic-go (v0.15.5 -> v0.15.7):
  - reset the PTO when dropping a packet number space
  - move deadlineTimer declaration out of the Read loop
  - stop the deadline timer in Stream.Read and Write
  - fix buffer use after it was released when sending an INVALID_TOKEN error
  - create the session timer at the beginning of the run loop
  - stop the timer when the session's run loop returns
ralendor pushed a commit to ralendor/go-ipfs that referenced this issue Jun 8, 2020
Hot on the heels of 0.5.0 is 0.5.1 with some important but small bug fixes. This release:

1. Removes the 1 minute timeout for IPNS publishes (fixes ipfs#7244).
2. Backport a DHT fix to reduce CPU usage for canceled requests.
3. Fixes some timer leaks in the QUIC transport ([ipfs#2515](quic-go/quic-go#2515)).

Full changelog:

- github.com/ipfs/go-ipfs:
  - IPNS timeout patch from master ([ipfs#7276](ipfs#7276))
- github.com/libp2p/go-libp2p-core (v0.5.2 -> v0.5.3):
  - feat: add a function to tell if a context subscribes to query events ([libp2p/go-libp2p-core#147](libp2p/go-libp2p-core#147))
- github.com/libp2p/go-libp2p-kad-dht (v0.7.10 -> v0.7.11):
  - fix: optimize for the case where we're not subscribing to query events ([libp2p/go-libp2p-kad-dht#624](libp2p/go-libp2p-kad-dht#624))
  - fix: don't spin when the event channel is closed ([libp2p/go-libp2p-kad-dht#622](libp2p/go-libp2p-kad-dht#622))
- github.com/libp2p/go-libp2p-routing-helpers (v0.2.2 -> v0.2.3):
  - fix: avoid subscribing to query events unless necessary ([libp2p/go-libp2p-routing-helpers#43](libp2p/go-libp2p-routing-helpers#43))
- github.com/lucas-clemente/quic-go (v0.15.5 -> v0.15.7):
  - reset the PTO when dropping a packet number space
  - move deadlineTimer declaration out of the Read loop
  - stop the deadline timer in Stream.Read and Write
  - fix buffer use after it was released when sending an INVALID_TOKEN error
  - create the session timer at the beginning of the run loop
  - stop the timer when the session's run loop returns
ralendor pushed a commit to ralendor/go-ipfs that referenced this issue Jun 8, 2020
Hot on the heels of 0.5.0 is 0.5.1 with some important but small bug fixes. This release:

1. Removes the 1 minute timeout for IPNS publishes (fixes ipfs#7244).
2. Backport a DHT fix to reduce CPU usage for canceled requests.
3. Fixes some timer leaks in the QUIC transport ([ipfs#2515](quic-go/quic-go#2515)).

Full changelog:

- github.com/ipfs/go-ipfs:
  - IPNS timeout patch from master ([ipfs#7276](ipfs#7276))
- github.com/libp2p/go-libp2p-core (v0.5.2 -> v0.5.3):
  - feat: add a function to tell if a context subscribes to query events ([libp2p/go-libp2p-core#147](libp2p/go-libp2p-core#147))
- github.com/libp2p/go-libp2p-kad-dht (v0.7.10 -> v0.7.11):
  - fix: optimize for the case where we're not subscribing to query events ([libp2p/go-libp2p-kad-dht#624](libp2p/go-libp2p-kad-dht#624))
  - fix: don't spin when the event channel is closed ([libp2p/go-libp2p-kad-dht#622](libp2p/go-libp2p-kad-dht#622))
- github.com/libp2p/go-libp2p-routing-helpers (v0.2.2 -> v0.2.3):
  - fix: avoid subscribing to query events unless necessary ([libp2p/go-libp2p-routing-helpers#43](libp2p/go-libp2p-routing-helpers#43))
- github.com/lucas-clemente/quic-go (v0.15.5 -> v0.15.7):
  - reset the PTO when dropping a packet number space
  - move deadlineTimer declaration out of the Read loop
  - stop the deadline timer in Stream.Read and Write
  - fix buffer use after it was released when sending an INVALID_TOKEN error
  - create the session timer at the beginning of the run loop
  - stop the timer when the session's run loop returns
ralendor pushed a commit to ralendor/go-ipfs that referenced this issue Jun 8, 2020
Hot on the heels of 0.5.0 is 0.5.1 with some important but small bug fixes. This release:

1. Removes the 1 minute timeout for IPNS publishes (fixes ipfs#7244).
2. Backport a DHT fix to reduce CPU usage for canceled requests.
3. Fixes some timer leaks in the QUIC transport ([ipfs#2515](quic-go/quic-go#2515)).

Full changelog:

- github.com/ipfs/go-ipfs:
  - IPNS timeout patch from master ([ipfs#7276](ipfs#7276))
- github.com/libp2p/go-libp2p-core (v0.5.2 -> v0.5.3):
  - feat: add a function to tell if a context subscribes to query events ([libp2p/go-libp2p-core#147](libp2p/go-libp2p-core#147))
- github.com/libp2p/go-libp2p-kad-dht (v0.7.10 -> v0.7.11):
  - fix: optimize for the case where we're not subscribing to query events ([libp2p/go-libp2p-kad-dht#624](libp2p/go-libp2p-kad-dht#624))
  - fix: don't spin when the event channel is closed ([libp2p/go-libp2p-kad-dht#622](libp2p/go-libp2p-kad-dht#622))
- github.com/libp2p/go-libp2p-routing-helpers (v0.2.2 -> v0.2.3):
  - fix: avoid subscribing to query events unless necessary ([libp2p/go-libp2p-routing-helpers#43](libp2p/go-libp2p-routing-helpers#43))
- github.com/lucas-clemente/quic-go (v0.15.5 -> v0.15.7):
  - reset the PTO when dropping a packet number space
  - move deadlineTimer declaration out of the Read loop
  - stop the deadline timer in Stream.Read and Write
  - fix buffer use after it was released when sending an INVALID_TOKEN error
  - create the session timer at the beginning of the run loop
  - stop the timer when the session's run loop returns
ralendor pushed a commit to ralendor/go-ipfs that referenced this issue Jun 8, 2020
Hot on the heels of 0.5.0 is 0.5.1 with some important but small bug fixes. This release:

1. Removes the 1 minute timeout for IPNS publishes (fixes ipfs#7244).
2. Backport a DHT fix to reduce CPU usage for canceled requests.
3. Fixes some timer leaks in the QUIC transport ([ipfs#2515](quic-go/quic-go#2515)).

Full changelog:

- github.com/ipfs/go-ipfs:
  - IPNS timeout patch from master ([ipfs#7276](ipfs#7276))
- github.com/libp2p/go-libp2p-core (v0.5.2 -> v0.5.3):
  - feat: add a function to tell if a context subscribes to query events ([libp2p/go-libp2p-core#147](libp2p/go-libp2p-core#147))
- github.com/libp2p/go-libp2p-kad-dht (v0.7.10 -> v0.7.11):
  - fix: optimize for the case where we're not subscribing to query events ([libp2p/go-libp2p-kad-dht#624](libp2p/go-libp2p-kad-dht#624))
  - fix: don't spin when the event channel is closed ([libp2p/go-libp2p-kad-dht#622](libp2p/go-libp2p-kad-dht#622))
- github.com/libp2p/go-libp2p-routing-helpers (v0.2.2 -> v0.2.3):
  - fix: avoid subscribing to query events unless necessary ([libp2p/go-libp2p-routing-helpers#43](libp2p/go-libp2p-routing-helpers#43))
- github.com/lucas-clemente/quic-go (v0.15.5 -> v0.15.7):
  - reset the PTO when dropping a packet number space
  - move deadlineTimer declaration out of the Read loop
  - stop the deadline timer in Stream.Read and Write
  - fix buffer use after it was released when sending an INVALID_TOKEN error
  - create the session timer at the beginning of the run loop
  - stop the timer when the session's run loop returns
@Lua12138
Copy link

When I visit such an address http://<host>:8080/ipfs/<CID>. I got an error message. What does it mean?
ipfs resolve -r /ipfs/<CID>: context deadline exceeded

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug A bug in existing code (including security flaws) need/triage Needs initial labeling and prioritization
Projects
None yet
Development

Successfully merging a pull request may close this issue.

10 participants