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

Connect to localhost fails on 0.35 #141

Open
christopherraa opened this issue Dec 5, 2022 · 8 comments
Open

Connect to localhost fails on 0.35 #141

christopherraa opened this issue Dec 5, 2022 · 8 comments

Comments

@christopherraa
Copy link

After the version bump and update of hiredis in 0.35 there is an issue where Redis::Fast is unable to connect to localhost:6379. On the other hand 127.0.0.1:6379 works without fail. This behaviour isn't seen on all hosts though. Example I used to reproduce this on one of the problematic hosts:

# Works fine, outputs nothing
perl -e 'use Redis::Fast; Redis::Fast->new(server => "127.0.0.1:6379")->keys("*");'

# Fails to connect, spits out error
perl -e 'use Redis::Fast; Redis::Fast->new(server => "localhost:6379")->keys("*");'
Could not connect to Redis server at localhost:6379 at [TRUNCATED].../local/lib/perl5/x86_64-linux/Redis/Fast.pm line 246.

On hosts where this is a problem version 0.34 works without failing, but version 0.35 fails on connect to localhost every time.

I don't quite know how to proceed in debugging this. What I have checked is that the system can resolve localhost just fine, and redis-cli also connects to the server just fine on both localhost and 127.0.0.1.

@shogo82148
Copy link
Owner

set the REDIS_DEBUG environment value, and then please show me the whole of log.

@christopherraa
Copy link
Author

Connection string that does not work:

$ REDIS_DEBUG=1 perl -e 'use Redis::Fast; Redis::Fast->new(server => "localhost:6379")->keys("*");'

[28726][1711][lib/Redis/Fast.xs:373:Redis__Fast_connect]: start
[28726][1711][lib/Redis/Fast.xs:292:__build_sock]: start
[28726][1711][lib/Redis/Fast.xs:119:AddWrite]: flags = 2
[28726][1711][lib/Redis/Fast.xs:199:wait_for_event]: set WRITE, write_timeout = -1.000000
[28726][1711][lib/Redis/Fast.xs:210:wait_for_event]: select start, timeout is -1.000000
[28726][1711][lib/Redis/Fast.xs:217:wait_for_event]: poll returns 1
[28726][1711][lib/Redis/Fast.xs:237:wait_for_event]: ready to write
[28726][1711][lib/Redis/Fast.xs:269:Redis__Fast_connect_cb]: connected status = -1
[28726][1711][lib/Redis/Fast.xs:244:wait_for_event]: exception: POLLERR
Could not connect to Redis server at localhost:6379 at [TRUNCATED].../local/lib/perl5/x86_64-linux/Redis/Fast.pm line 246.
[28726][1711][lib/Redis/Fast.xs:1162:XS_Redis__Fast_DESTROY]: start
[28726][1711][lib/Redis/Fast.xs:1171:XS_Redis__Fast_DESTROY]: free hostname
[28726][1711][lib/Redis/Fast.xs:1183:XS_Redis__Fast_DESTROY]: free error
[28726][1711][lib/Redis/Fast.xs:1189:XS_Redis__Fast_DESTROY]: free on_connect
[28726][1711][lib/Redis/Fast.xs:1201:XS_Redis__Fast_DESTROY]: free data
[28726][1711][lib/Redis/Fast.xs:1212:XS_Redis__Fast_DESTROY]: finish

Connection string that works:

$ REDIS_DEBUG=1 perl -e 'use Redis::Fast; Redis::Fast->new(server => "127.0.0.1:6379")->keys("*");'

[495][1711][lib/Redis/Fast.xs:373:Redis__Fast_connect]: start
[495][1711][lib/Redis/Fast.xs:292:__build_sock]: start
[495][1711][lib/Redis/Fast.xs:119:AddWrite]: flags = 2
[495][1711][lib/Redis/Fast.xs:199:wait_for_event]: set WRITE, write_timeout = -1.000000
[495][1711][lib/Redis/Fast.xs:210:wait_for_event]: select start, timeout is -1.000000
[495][1711][lib/Redis/Fast.xs:217:wait_for_event]: poll returns 1
[495][1711][lib/Redis/Fast.xs:237:wait_for_event]: ready to write
[495][1711][lib/Redis/Fast.xs:269:Redis__Fast_connect_cb]: connected status = 0
[495][1711][lib/Redis/Fast.xs:126:DelWrite]: flags = 0
[495][1711][lib/Redis/Fast.xs:105:AddRead]: flags = 1
[495][1711][lib/Redis/Fast.xs:248:wait_for_event]: finish
[495][1711][lib/Redis/Fast.xs:365:__build_sock]: finish
[495][1711][lib/Redis/Fast.xs:423:Redis__Fast_reconnect]: start
[495][1711][lib/Redis/Fast.xs:431:Redis__Fast_reconnect]: finish
[495][1711][lib/Redis/Fast.xs:760:Redis__Fast_run_cmd]: start KEYS
[495][1711][lib/Redis/Fast.xs:762:Redis__Fast_run_cmd]: pid check: previous pid is 495, now 495
[495][1711][lib/Redis/Fast.xs:807:Redis__Fast_run_cmd]: send command in sync mode
[495][1711][lib/Redis/Fast.xs:119:AddWrite]: flags = 3
[495][1711][lib/Redis/Fast.xs:812:Redis__Fast_run_cmd]: waiting response
[495][1711][lib/Redis/Fast.xs:254:_wait_all_responses]: start
[495][1711][lib/Redis/Fast.xs:177:wait_for_event]: set READ and WRITE, compare read_timeout = -1.000000 and write_timeout = -1.000000
[495][1711][lib/Redis/Fast.xs:210:wait_for_event]: select start, timeout is -1.000000
[495][1711][lib/Redis/Fast.xs:217:wait_for_event]: poll returns 1
[495][1711][lib/Redis/Fast.xs:237:wait_for_event]: ready to write
[495][1711][lib/Redis/Fast.xs:126:DelWrite]: flags = 1
[495][1711][lib/Redis/Fast.xs:105:AddRead]: flags = 1
[495][1711][lib/Redis/Fast.xs:248:wait_for_event]: finish
[495][1711][lib/Redis/Fast.xs:195:wait_for_event]: set READ, read_timeout = -1.000000
[495][1711][lib/Redis/Fast.xs:210:wait_for_event]: select start, timeout is -1.000000
[495][1711][lib/Redis/Fast.xs:217:wait_for_event]: poll returns 1
[495][1711][lib/Redis/Fast.xs:233:wait_for_event]: ready to read
[495][1711][lib/Redis/Fast.xs:105:AddRead]: flags = 1
[495][1711][lib/Redis/Fast.xs:545:Redis__Fast_sync_reply_cb]: 0x5647448f4c80
[495][1711][lib/Redis/Fast.xs:562:Redis__Fast_sync_reply_cb]: finish
[495][1711][lib/Redis/Fast.xs:248:wait_for_event]: finish
[495][1711][lib/Redis/Fast.xs:262:_wait_all_responses]: finish
[495][1711][lib/Redis/Fast.xs:828:Redis__Fast_run_cmd]: finish KEYS
[495][1711][lib/Redis/Fast.xs:1162:XS_Redis__Fast_DESTROY]: start
[495][1711][lib/Redis/Fast.xs:1164:XS_Redis__Fast_DESTROY]: free ac
[495][1711][lib/Redis/Fast.xs:282:Redis__Fast_disconnect_cb]: disconnected status = 0
[495][1711][lib/Redis/Fast.xs:254:_wait_all_responses]: start
[495][1711][lib/Redis/Fast.xs:262:_wait_all_responses]: finish
[495][1711][lib/Redis/Fast.xs:1171:XS_Redis__Fast_DESTROY]: free hostname
[495][1711][lib/Redis/Fast.xs:1183:XS_Redis__Fast_DESTROY]: free error
[495][1711][lib/Redis/Fast.xs:1189:XS_Redis__Fast_DESTROY]: free on_connect
[495][1711][lib/Redis/Fast.xs:1201:XS_Redis__Fast_DESTROY]: free data
[495][1711][lib/Redis/Fast.xs:1212:XS_Redis__Fast_DESTROY]: finish

@shogo82148
Copy link
Owner

Hmm, I cannot reproduce it.
Please more information, OS, the version of Perl, etc.

@christopherraa
Copy link
Author

Ok, so I figured it out by running everything through strace and wading through the output. There I discovered that localhost was resolved to ::1 when running through Perl, but 127.0.0.1 when running other system applications such as ping etc. The redis server was only listening on 127.0.0.1. Once I configured the redis server to listen on ::1 as well both forms of connection string worked (127.0.0.1 and localhost).

Perhaps it would be useful if the output from the module listed what it actually tried to connect to (ie. what was resolved)? Something like the following output would have me see the issue immediately:

Could not connect to Redis server at localhost:6379 (::1:6379) at [TRUNCATED].../local/lib/perl5/x86_64-linux/Redis/Fast.pm line 246.

or

Could not connect to Redis server at ::1:6379 for connection string 'localhost:6379' at [TRUNCATED].../local/lib/perl5/x86_64-linux/Redis/Fast.pm line 246.

What do you think? That additional bit of information would definitly have saved me (and you) quite some time debugging.

@shogo82148
Copy link
Owner

It needs to apply some patches to hiredis.
I want not to do that.

redis/hiredis#1096 would be related, but we do not know why.

@christopherraa
Copy link
Author

Thank you for taking the time to followin up on this, and for linking to the other issue. I'll go ahead and close this one now.

@oschwald
Copy link

oschwald commented Jan 10, 2023

We also ran into this when upgrading to 0.35. For us it is happening on Ubuntu 20.04 and 22.10 with Perl 5.36.0.

The underlying reason appears to be that we were connecting to localhost but the Redis server was bound to 127.0.0.1. In 0.35, localhost resolves to ::1, despite comments in hiredis code saying that IPv4 will be tried first if no preference is specified.

@christopherraa
Copy link
Author

Based on the comment by @oschwald perhaps this issue is better reopened.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants