View Issue Details

IDProjectCategoryView StatusLast Update
0006663Talermechant backendpublic2021-01-29 22:50
Reportersebasjm Assigned ToChristian Grothoff  
PrioritynormalSeveritymajorReproducibilityalways
Status closedResolutionno change required 
PlatformlinuxOSalpineOS Version20200917
Product Versiongit (master) 
Target Version0.8Fixed in Version0.8 
Summary0006663: merchant query to exchange (request_keys) does not work
DescriptionHello! first time setting up taler so it took me some time to be sure that is not a config problem (and I hope it isnt)

Im building all from scratch into an alpine SO. Im able to withdraw and use the browser wallet with a custom currency (ARS).
The problem comes when I try to spend it, the request to the merchant fails with timeout after 10 seconds.
Looking at the logs I found the exchange never gets the request from the merchant, thats explain the merchant timeouting.

Exploring deeper the logs I found the merchant repeats the query to the exchange looking for the keys.
> INFO Received keys from URL `http://exchange.taler:8282/keys' with status 0.
but the exchange never logs the request, I expected to announce that is responding to the /keys like when it being curled but failed.

That lead me to think that the merchant is not querying in a proper way.
I have setup an netcat process with the option of dumping the content into a file. This process get the connection from the merchant but no HTTP request is being received.

For an easy reproduction of the problem Im attaching some docker file that I made for this report. Im able to reproduce it 100% in this environment.
Steps To Reproducedocker build -t taler/base base
docker build -t taler/exchange exchange
docker build -t taler/merchant merchant

docker run -it --entrypoint=/bin/ash --volume $PWD/merchant-test.conf:/root/.config/taler.conf taler/merchant

~ # nc -vvv -l -p 8282

```
listening on [::]:8282 ...
connect to [::ffff:127.0.0.1]:8282 from localhost:46920 ([::ffff:127.0.0.1]:46920)
```

expecting to see something like

```
listening on [::]:8282 ...
connect to [::ffff:172.17.0.2]:8282 from [::ffff:172.17.0.1]:47744 ([::ffff:172.17.0.1]:47744)
GET /keys HTTP/1.1
Host: localhost:8282
User-Agent: curl/7.58.0
Accept: */*
```



Additional InformationThis setups needs a postgresql server running on the host but its not related to the problem.
TagsNo tags attached.

Activities

sebasjm

2020-12-08 13:51

developer  

report.zip (2,930 bytes)

Florian Dold

2020-12-08 14:41

manager   ~0017166

Did you set the port of the exchange to 8082 in the configuration?

It looks like the merchant expects the exchange to be running on 8082, but per default [1] the exchange runs on 8081.

[1] https://git.taler.net/exchange.git/tree/src/exchange/exchange.conf#n45

sebasjm

2020-12-08 15:35

developer   ~0017167

Yes, working with all the environment the exchange is running ok and I can withdraw as expected with the browser wallet and the provided bank.
Also, running `curl http://exchange.taler:8282/keys` in the same machine as the merchant is running the `curl` process get the keys as expected and the exchange logs the requests being received.

In the files attached I have setup the merchant configuration to query http://localhost:8282/keys because I used as a tests running a netcat process in that port and in the local machine.

Christian Grothoff

2020-12-08 15:40

manager   ~0017168

Status 0 indeed is used to indicate that we failed to even get an HTTP-response from the exchange. Could also be a DNS failure on the hostname lookup or some other issue (maybe the port number was lost on the way somewhere?). Didn't check your configuration yet in detail though, so these are only speculations based on the status code of 0.

sebasjm

2020-12-08 16:00

developer   ~0017169

I will do some test using ip only, no port and using default ports in order to be sure but I think that I checked that variants.

Thanks in advance

sebasjm

2020-12-08 18:28

developer   ~0017170

I can confirm that removing the port, using default 8081 ports and avoid using host names does not bring any difference.

I will highlight that in the setup I have attached I used a netcat process (in behalf of the exchange) to debug how the merchant is building the request and Ive found:
1.- the merchant is connecting to the process (in port 8282, or any port if its configured properly)
2.- the netcat process does not show any content being received (I expect to see an HTTP request text)

Christian Grothoff

2020-12-08 18:51

manager   ~0017171

One thing: I may have recently created a regression in the exchange logic (ongoing private discussion with Florian, reported today!). Which version of the exchange are you using? If it is Git master, could you try going back a week or two?

sebasjm

2020-12-08 19:03

developer   ~0017172

In the exchange I'm using v0.8.1, gnunet v0.14.0 and merchant v0.8.0
All directly from the git branch, you can see more detailed information in the dockerfiles about the configure parameters and the exact steps used to build the binary.
Since the docker image is fresh from the last alpine public docker image there is also a detailed list of packages installed needed to build all the sources.

sebasjm

2021-01-05 21:21

developer   ~0017304

Deep inspect into the build process found some problems in gnunet tests. Basically `./src/util/test_service.c` was failing with error code 33 (timeout) because I didnt have ipv6 enabled in the computer running the tests.
After commenting that configuration under /etc/sysctl.conf [1], tests under gnunet passed and merchant query to exchange works ok.

Doing some further tests, changing enabling/disabling ipv6 at runtime doesnt not seems to change the behavior. So I think it may be related to the building process.
I can go deeper into this but it works for me right now.

Christian Grothoff

2021-01-06 15:56

manager   ~0017312

I guess if your system's resolver returns an IPv6-address for 'localhost', and you block loopback on IPv6, then indeed bad things are expected to happen for basically anything test-suite related. Also yes, the GNUnet test suite would fail. So I guess this bug falls under "gracefully handle systems without IPv6"? Could you say which exact sysctl.conf you changed?

sebasjm

2021-01-06 19:44

developer   ~0017314

Yes, this is what I had in `/etc/sysctl.conf` I forgot to paste it

net.ipv6.conf.all.use_tempaddr=0
net.ipv6.conf.default.use_tempaddr=0
net.ipv6.conf.all.disable_ipv6=1
net.ipv6.conf.default.disable_ipv6=1

> So I guess this bug falls under "gracefully handle systems without IPv6"?

Definitely.

Christian Grothoff

2021-01-16 18:50

manager   ~0017360

I've checked this some more, and curl does implement RFC 6555, so it _should_ automatically try both v4 and v6 and _should_ already succeed even if you blocked v6. So the only scenario where this would fail should be if you block v6 and on DNS (for 'localhost') only return an IPv6 address. Then Happy Eyeballs doesn't have a v4 fallback option. But in this case, your config is just so messed up, that you really ought not expect this to work...

Christian Grothoff

2021-01-16 18:57

manager   ~0017361

I've tested it on my system, and it works if I _merely_ disable IPv6 (disable_ipv6=1). Note that my /etc/hosts contains:
127.0.0.1 localhost
::1 localhost ip6-localhost ip6-loopback

If you leave out the first line, it cannot work.

Christian Grothoff

2021-01-16 18:59

manager   ~0017362

As for GNUnet's "test_service", it does check if the kernel supports IPv6. The test then checks that loopback communication works with IPv6. Your Kernel option allows the creation of IPv6 sockets (!), but then doesn't allow them to work at all. Which is bad. So I think that test rightfully fails, as a system with that configuration will create major problems for the peer: we'll always try v6, and it'll never work.

Issue History

Date Modified Username Field Change
2020-12-08 13:51 sebasjm New Issue
2020-12-08 13:51 sebasjm Status new => assigned
2020-12-08 13:51 sebasjm Assigned To => Christian Grothoff
2020-12-08 13:51 sebasjm File Added: report.zip
2020-12-08 14:41 Florian Dold Note Added: 0017166
2020-12-08 14:41 Florian Dold Assigned To Christian Grothoff =>
2020-12-08 14:41 Florian Dold Status assigned => feedback
2020-12-08 15:35 sebasjm Note Added: 0017167
2020-12-08 15:35 sebasjm Status feedback => new
2020-12-08 15:40 Christian Grothoff Note Added: 0017168
2020-12-08 16:00 sebasjm Note Added: 0017169
2020-12-08 18:28 sebasjm Note Added: 0017170
2020-12-08 18:51 Christian Grothoff Note Added: 0017171
2020-12-08 19:03 sebasjm Note Added: 0017172
2021-01-05 21:21 sebasjm Note Added: 0017304
2021-01-06 15:56 Christian Grothoff Note Added: 0017312
2021-01-06 15:56 Christian Grothoff Assigned To => Christian Grothoff
2021-01-06 15:56 Christian Grothoff Status new => assigned
2021-01-06 15:57 Christian Grothoff Status assigned => feedback
2021-01-06 19:44 sebasjm Note Added: 0017314
2021-01-06 19:44 sebasjm Status feedback => assigned
2021-01-16 18:50 Christian Grothoff Note Added: 0017360
2021-01-16 18:57 Christian Grothoff Note Added: 0017361
2021-01-16 18:59 Christian Grothoff Note Added: 0017362
2021-01-29 22:50 Christian Grothoff Status assigned => closed
2021-01-29 22:50 Christian Grothoff Resolution open => no change required
2021-01-29 22:50 Christian Grothoff Product Version => git (master)
2021-01-29 22:50 Christian Grothoff Fixed in Version => 0.8
2021-01-29 22:50 Christian Grothoff Target Version => 0.8
2021-01-29 22:50 Christian Grothoff Description Updated View Revisions
2021-01-29 22:50 Christian Grothoff Steps to Reproduce Updated View Revisions
2021-01-29 22:50 Christian Grothoff Additional Information Updated View Revisions