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

grpc client does not respect SIGINT when it can't connect to the server #4148

Closed
mightyguava opened this issue Nov 18, 2015 · 24 comments
Closed

Comments

@mightyguava
Copy link

I have a very simple Python app that looks like

  stub = demo_pb2.beta_create_DemoService_stub(
    demo_pb2.beta_implementations.insecure_channel('localhost', 50051))
  response = stub.Bar(demo_pb2.DemoRequest(ii=15, foo='blah'), 10)
  print response

When I don't run the server, I'm not able to kill the app with Ctrl-C, no matter how many times I press it. Is grpc trapping the signal somewhere? This reproduces for me in Python and Node, haven't tried other implementations.

E1117 20:00:40.431769000 4563509248 tcp_client_posix.c:159] socket error: connection refused
E1117 20:00:41.435356000 4563509248 tcp_client_posix.c:159] socket error: connection refused
E1117 20:00:43.133662000 4563509248 tcp_client_posix.c:159] socket error: connection refused
^CE1117 20:00:45.540944000 4563509248 tcp_client_posix.c:159] socket error: connection refused
^C^C^C^CE1117 20:00:50.295463000 4563509248 tcp_client_posix.c:159] socket error: connection refused
E1117 20:00:57.922300000 4563509248 tcp_client_posix.c:159] socket error: connection refused
E1117 20:01:08.157532000 4563509248 tcp_client_posix.c:159] socket error: connection refused
E1117 20:01:22.029306000 4563509248 tcp_client_posix.c:159] socket error: connection refused
^C^C^C^C^C^CE1117 20:01:48.197681000 4563509248 tcp_client_posix.c:159] socket error: connection refused
E1117 20:02:27.986067000 4563509248 tcp_client_posix.c:159] socket error: connection refused
E1117 20:03:42.654656000 4563509248 tcp_client_posix.c:159] socket error: connection refused
@mightyguava mightyguava changed the title grpc client does not respect SIGINT when it can't find connect to the server grpc client does not respect SIGINT when it can't connect to the server Nov 18, 2015
@robert-w-gries
Copy link

I get a similar error in Ruby.

E1120 11:39:02.721717913   11350 tcp_client_posix.c:171]     failed to connect to 'ipv4:[snip]'': socket error: connection refused
E1120 11:39:06.084193935   11350 tcp_client_posix.c:171]     failed to connect to 'ipv4:[snip]': socket error: connection refused
^CE1120 11:39:06.761210458   11350 pollset_posix.c:615]        poll() failed: Interrupted system call
^CE1120 11:39:07.150115269   11350 pollset_posix.c:615]        poll() failed: Interrupted system call
^CE1120 11:39:07.481402747   11350 pollset_posix.c:615]        poll() failed: Interrupted system call

@soltanmm
Copy link
Contributor

soltanmm commented Dec 8, 2015

@ctiller Could this be a core issue?

@ctiller
Copy link
Member

ctiller commented Dec 8, 2015

Core does no signal handling nor masking AFAIK. It's most certainly a
language runtime issue.

On Mon, Dec 7, 2015, 6:40 PM Masood Malekghassemi notifications@github.com
wrote:

@ctiller https://github.com/ctiller Could this be a core issue?


Reply to this email directly or view it on GitHub
#4148 (comment).

@soltanmm
Copy link
Contributor

soltanmm commented Dec 8, 2015

I mean the behavior wherein it's not timing out.

@ctiller
Copy link
Member

ctiller commented Dec 8, 2015

I'm not aware of such. That doesn't mean no of course :)

Getting a log with the environment variable GRPC_TRACE=api set would help pin point this.

@glennmatthews
Copy link

GRPC_TRACE=api doesn't seem to produce any more context around the above errors - I'm not sure which 'not timing out' issue is being referenced but I see timeouts and the client still doesn't exit, nor is any more information output as a trace:

key=username value=61 64 6d 69 6e 'admin'
key=password value=61 64 6d 69 6e 'admin'
I1209 08:32:54.711147847   20848 completion_queue.c:299]     grpc_completion_queue_pluck(cc=0x7fda3433b700, tag=0x7fda33b387f0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
E1209 08:33:14.712384519   20848 tcp_client_posix.c:189]     failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
^CE1209 08:33:18.976988549   20848 pollset_posix.c:586]        poll() failed: Interrupted system call
E1209 08:33:34.713791796   20848 tcp_client_posix.c:189]     failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
E1209 08:33:54.715110450   20848 tcp_client_posix.c:189]     failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
E1209 08:34:14.715862777   20848 tcp_client_posix.c:189]     failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
^CE1209 08:34:18.254087178   20848 pollset_posix.c:586]        poll() failed: Interrupted system call
^CE1209 08:34:18.465998553   20848 pollset_posix.c:586]        poll() failed: Interrupted system call
^CE1209 08:34:18.622815445   20848 pollset_posix.c:586]        poll() failed: Interrupted system call
^CE1209 08:34:18.770786906   20848 pollset_posix.c:586]        poll() failed: Interrupted system call

And:

key=username value=61 64 6d 69 6e 'admin'
key=password value=61 64 6d 69 6e 'admin'
I1209 08:36:57.282907648   30150 completion_queue.c:299]     grpc_completion_queue_pluck(cc=0x7ffaf0d81d20, tag=0x7ffaf059e078, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
E1209 08:36:57.291454844   30150 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1209 08:36:58.295314157   30150 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1209 08:36:59.878612254   30150 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1209 08:37:02.073967062   30150 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
^CE1209 08:37:04.074368272   30150 pollset_posix.c:586]        poll() failed: Interrupted system call
^CE1209 08:37:05.034939199   30150 pollset_posix.c:586]        poll() failed: Interrupted system call
^CE1209 08:37:05.542907553   30150 pollset_posix.c:586]        poll() failed: Interrupted system call
E1209 08:37:05.836388017   30150 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
^CE1209 08:37:05.974189365   30150 pollset_posix.c:586]        poll() failed: Interrupted system call
^CE1209 08:37:06.309551621   30150 pollset_posix.c:586]        poll() failed: Interrupted system call
^CE1209 08:37:06.894374781   30150 pollset_posix.c:586]        poll() failed: Interrupted system call

@ctiller
Copy link
Member

ctiller commented Dec 9, 2015

Can you post the log lines around grpc_channel_create_call?

On Wed, Dec 9, 2015, 5:29 AM Glenn Matthews notifications@github.com
wrote:

GRPC_TRACE=api doesn't seem to produce any more context around the above
errors - I'm not sure which 'not timing out' issue is being referenced but
I see timeouts and the client still doesn't exit, nor is any more
information output as a trace:

key=username value=61 64 6d 69 6e 'admin'
key=password value=61 64 6d 69 6e 'admin'
I1209 08:32:54.711147847 20848 completion_queue.c:299] grpc_completion_queue_pluck(cc=0x7fda3433b700, tag=0x7fda33b387f0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
E1209 08:33:14.712384519 20848 tcp_client_posix.c:189] failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
^CE1209 08:33:18.976988549 20848 pollset_posix.c:586] poll() failed: Interrupted system call
E1209 08:33:34.713791796 20848 tcp_client_posix.c:189] failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
E1209 08:33:54.715110450 20848 tcp_client_posix.c:189] failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
E1209 08:34:14.715862777 20848 tcp_client_posix.c:189] failed to connect to 'ipv4:192.168.1.1:3583': timeout occurred
^CE1209 08:34:18.254087178 20848 pollset_posix.c:586] poll() failed: Interrupted system call
^CE1209 08:34:18.465998553 20848 pollset_posix.c:586] poll() failed: Interrupted system call
^CE1209 08:34:18.622815445 20848 pollset_posix.c:586] poll() failed: Interrupted system call
^CE1209 08:34:18.770786906 20848 pollset_posix.c:586] poll() failed: Interrupted system call

And:

key=username value=61 64 6d 69 6e 'admin'
key=password value=61 64 6d 69 6e 'admin'
I1209 08:36:57.282907648 30150 completion_queue.c:299] grpc_completion_queue_pluck(cc=0x7ffaf0d81d20, tag=0x7ffaf059e078, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
E1209 08:36:57.291454844 30150 tcp_client_posix.c:171] failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1209 08:36:58.295314157 30150 tcp_client_posix.c:171] failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1209 08:36:59.878612254 30150 tcp_client_posix.c:171] failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1209 08:37:02.073967062 30150 tcp_client_posix.c:171] failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
^CE1209 08:37:04.074368272 30150 pollset_posix.c:586] poll() failed: Interrupted system call
^CE1209 08:37:05.034939199 30150 pollset_posix.c:586] poll() failed: Interrupted system call
^CE1209 08:37:05.542907553 30150 pollset_posix.c:586] poll() failed: Interrupted system call
E1209 08:37:05.836388017 30150 tcp_client_posix.c:171] failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
^CE1209 08:37:05.974189365 30150 pollset_posix.c:586] poll() failed: Interrupted system call
^CE1209 08:37:06.309551621 30150 pollset_posix.c:586] poll() failed: Interrupted system call
^CE1209 08:37:06.894374781 30150 pollset_posix.c:586] poll() failed: Interrupted system call


Reply to this email directly or view it on GitHub
#4148 (comment).

@glennmatthews
Copy link

I1209 08:36:57.280874372   30150 completion_queue.c:91]      grpc_completion_queue_create(reserved=(nil))
I1209 08:36:57.281033686   30150 channel_create.c:190]       grpc_insecure_channel_create(target=0x7ffaf05a2700, args=0x7ffd7c5d81f0, reserved=(nil))
I1209 08:36:57.281166727   30150 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=0, name=0x7ffd7c5d7fe8)
I1209 08:36:57.281243869   30150 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=1, name=0x7ffd7c5d7fe8)
I1209 08:36:57.281308930   30150 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=2, name=0x7ffd7c5d7fe8)
I1209 08:36:57.281428085   30150 completion_queue.c:91]      grpc_completion_queue_create(reserved=(nil))
I1209 08:36:57.281527268   30150 channel_create.c:190]       grpc_insecure_channel_create(target=0x7ffaf05a2700, args=0x7ffd7c5d82d0, reserved=(nil))
I1209 08:36:57.281612403   30150 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=0, name=0x7ffd7c5d80c8)
I1209 08:36:57.281678384   30150 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=1, name=0x7ffd7c5d80c8)
I1209 08:36:57.281750365   30150 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=2, name=0x7ffd7c5d80c8)
I1209 08:36:57.281937570   30150 channel.c:226]              grpc_channel_create_call(channel=0x7ffaf0d822d0, parent_call=(nil), propagation_mask=ffff, cq=0x7ffaf0d81d20, method=<snip>, host=(null), deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1209 08:36:57.282112387   30150 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffd7c5d80f8)
I1209 08:36:57.282190418   30150 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffd7c5d8110)
I1209 08:36:57.282252666   30150 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffd7c5d8130)
I1209 08:36:57.282312922   30150 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffd7c5d8148)
I1209 08:36:57.282378188   30150 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffd7c5d80f8)
I1209 08:36:57.282450160   30150 call.c:1667]                grpc_call_start_batch(call=0x7ffaf0d83ae0, ops=0x7ffd7c5d7e70, nops=1, tag=0x7ffaf059e078, reserved=(nil))
I1209 08:36:57.282517496   30150 call.c:1674]                grpc_call_start_batch(call=0x7ffaf0d83ae0, ops=0x7ffd7c5d7e70, nops=1, tag=0x7ffaf059e078)
I1209 08:36:57.282604773   30150 call.c:1674]                ops[0]: SEND_INITIAL_METADATA
key=jwt_aud_uri value=68 74 74 70 73 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 32 32 2e 32 32 32 3a 33 34 39 35 30 2f 49 4f 53 58 52 45 78 74 65 6e 73 69 62 6c 65 4d 61 6e 61 67 61 62 69 6c 69 74 79 53 65 72 76 69 63 65 2e 67 52 50 43 45 78 65 63 'https://192.168.122.222:34950/<snip>'

@ctiller
Copy link
Member

ctiller commented Dec 9, 2015

Masood:

I1209 08:36:57.281937570 30150 channel.c:226]
grpc_channel_create_call(channel=0x7ffaf0d822d0, parent_call=(nil),
propagation_mask=ffff, cq=0x7ffaf0d81d20, method=, host=(null),
deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0,
clock_type: 1 }, reserved=(nil))

The timeout problem seems to be somewhere in the Python layer also (I see
inf timeout here).

On Wed, Dec 9, 2015, 5:58 AM Glenn Matthews notifications@github.com
wrote:

I1209 08:36:57.280874372 30150 completion_queue.c:91] grpc_completion_queue_create(reserved=(nil))
I1209 08:36:57.281033686 30150 channel_create.c:190] grpc_insecure_channel_create(target=0x7ffaf05a2700, args=0x7ffd7c5d81f0, reserved=(nil))
I1209 08:36:57.281166727 30150 algorithm.c:71] grpc_compression_algorithm_parse(algorithm=0, name=0x7ffd7c5d7fe8)
I1209 08:36:57.281243869 30150 algorithm.c:71] grpc_compression_algorithm_parse(algorithm=1, name=0x7ffd7c5d7fe8)
I1209 08:36:57.281308930 30150 algorithm.c:71] grpc_compression_algorithm_parse(algorithm=2, name=0x7ffd7c5d7fe8)
I1209 08:36:57.281428085 30150 completion_queue.c:91] grpc_completion_queue_create(reserved=(nil))
I1209 08:36:57.281527268 30150 channel_create.c:190] grpc_insecure_channel_create(target=0x7ffaf05a2700, args=0x7ffd7c5d82d0, reserved=(nil))
I1209 08:36:57.281612403 30150 algorithm.c:71] grpc_compression_algorithm_parse(algorithm=0, name=0x7ffd7c5d80c8)
I1209 08:36:57.281678384 30150 algorithm.c:71] grpc_compression_algorithm_parse(algorithm=1, name=0x7ffd7c5d80c8)
I1209 08:36:57.281750365 30150 algorithm.c:71] grpc_compression_algorithm_parse(algorithm=2, name=0x7ffd7c5d80c8)
I1209 08:36:57.281937570 30150 channel.c:226] grpc_channel_create_call(channel=0x7ffaf0d822d0, parent_call=(nil), propagation_mask=ffff, cq=0x7ffaf0d81d20, method=, host=(null), deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1209 08:36:57.282112387 30150 metadata_array.c:42] grpc_metadata_array_init(array=0x7ffd7c5d80f8)
I1209 08:36:57.282190418 30150 metadata_array.c:42] grpc_metadata_array_init(array=0x7ffd7c5d8110)
I1209 08:36:57.282252666 30150 metadata_array.c:42] grpc_metadata_array_init(array=0x7ffd7c5d8130)
I1209 08:36:57.282312922 30150 metadata_array.c:42] grpc_metadata_array_init(array=0x7ffd7c5d8148)
I1209 08:36:57.282378188 30150 metadata_array.c:42] grpc_metadata_array_init(array=0x7ffd7c5d80f8)
I1209 08:36:57.282450160 30150 call.c:1667] grpc_call_start_batch(call=0x7ffaf0d83ae0, ops=0x7ffd7c5d7e70, nops=1, tag=0x7ffaf059e078, reserved=(nil))
I1209 08:36:57.282517496 30150 call.c:1674] grpc_call_start_batch(call=0x7ffaf0d83ae0, ops=0x7ffd7c5d7e70, nops=1, tag=0x7ffaf059e078)
I1209 08:36:57.282604773 30150 call.c:1674] ops[0]: SEND_INITIAL_METADATA
key=jwt_aud_uri value=68 74 74 70 73 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 32 32 2e 32 32 32 3a 33 34 39 35 30 2f 49 4f 53 58 52 45 78 74 65 6e 73 69 62 6c 65 4d 61 6e 61 67 61 62 69 6c 69 74 79 53 65 72 76 69 63 65 2e 67 52 50 43 45 78 65 63 'https://192.168.122.222:34950/'


Reply to this email directly or view it on GitHub
#4148 (comment).

@soltanmm
Copy link
Contributor

Ew.

@glennmatthews what exactly was the code that you ran? (I ask because previous code in this thread sets the timeout to ten seconds and I want to know what you did and whether or not something else may be broken)

@soltanmm
Copy link
Contributor

@ctiller Oh, but, yes, the SIGINT thing is definitely a language runtime thing that should be addressed. I'm meandering a bit off-topic here because I'd have at least expected the SIGINT to work after a timeout.

@glennmatthews
Copy link

      @update_metadata = proc do |md|
        md[:username] = username
        md[:password] = password
        md
      end
      @exec = GRPCExec::Stub.new(address,
                                 update_metadata: @update_metadata)
      @timeout = nil

...

response = stub.send(type, args, timeout: @timeout)

If I set timeout to a numeric value, it does time out and fail on its own, raising a GRPC::BadStatus with DEADLINE_EXCEEDED status code, which appears to be correct.

If I have a timeout number, but Ctrl-C during the failure, here's the log:

I1210 10:04:06.871205821   22224 completion_queue.c:91]      grpc_completion_queue_create(reserved=(nil))
I1210 10:04:06.871312450   22224 channel_create.c:190]       grpc_insecure_channel_create(target=0x7f18d2e10d98, args=0x7ffdd9a98060, reserved=(nil))
I1210 10:04:06.871400204   22224 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=0, name=0x7ffdd9a97e58)
I1210 10:04:06.871422779   22224 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=1, name=0x7ffdd9a97e58)
I1210 10:04:06.871436318   22224 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=2, name=0x7ffdd9a97e58)
I1210 10:04:06.871506405   22224 completion_queue.c:91]      grpc_completion_queue_create(reserved=(nil))
I1210 10:04:06.871553302   22224 channel_create.c:190]       grpc_insecure_channel_create(target=0x7f18d2e10d98, args=0x7ffdd9a98140, reserved=(nil))
I1210 10:04:06.871581171   22224 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=0, name=0x7ffdd9a97f38)
I1210 10:04:06.871594454   22224 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=1, name=0x7ffdd9a97f38)
I1210 10:04:06.871606094   22224 algorithm.c:71]             grpc_compression_algorithm_parse(algorithm=2, name=0x7ffdd9a97f38)
I1210 10:04:06.871765241   22224 channel.c:226]              grpc_channel_create_call(channel=0x7f18d328c2d0, parent_call=(nil), propagation_mask=ffff, cq=0x7f18d328be20, method=/IOSXRExtensibleManagabilityService.gRPCExec/ShowCmdTextOutput, host=(null), deadline=gpr_timespec { tv_sec: 1449759876, tv_nsec: 871745051, clock_type: 1 }, reserved=(nil))
I1210 10:04:06.871942613   22224 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffdd9a97f68)
I1210 10:04:06.871965099   22224 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffdd9a97f80)
I1210 10:04:06.871976015   22224 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffdd9a97fa0)
I1210 10:04:06.871985726   22224 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffdd9a97fb8)
I1210 10:04:06.871999319   22224 metadata_array.c:42]        grpc_metadata_array_init(array=0x7ffdd9a97f68)
I1210 10:04:06.872016904   22224 call.c:1667]                grpc_call_start_batch(call=0x7f18d328d6a0, ops=0x7ffdd9a97ce0, nops=1, tag=0x7f18d2e0fc30, reserved=(nil))
I1210 10:04:06.872031242   22224 call.c:1674]                grpc_call_start_batch(call=0x7f18d328d6a0, ops=0x7ffdd9a97ce0, nops=1, tag=0x7f18d2e0fc30)
I1210 10:04:06.872061878   22224 call.c:1674]                ops[0]: SEND_INITIAL_METADATA
key=jwt_aud_uri value=68 74 74 70 73 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 32 32 2e 32 32 32 3a 33 34 39 35 30 2f 49 4f 53 58 52 45 78 74 65 6e 73 69 62 6c 65 4d 61 6e 61 67 61 62 69 6c 69 74 79 53 65 72 76 69 63 65 2e 67 52 50 43 45 78 65 63 'https://192.168.122.222:34950/IOSXRExtensibleManagabilityService.gRPCExec'
key=username value=61 'a'
key=password value=62 'b'
I1210 10:04:06.872184435   22224 completion_queue.c:299]     grpc_completion_queue_pluck(cc=0x7f18d328be20, tag=0x7f18d2e0fc30, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
E1210 10:04:06.881822793   22224 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1210 10:04:07.877634461   22224 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1210 10:04:09.471371799   22224 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
^CE1210 10:04:11.106609644   22224 pollset_posix.c:586]        poll() failed: Interrupted system call
E1210 10:04:11.657818213   22224 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1210 10:04:15.425755776   22224 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
^CE1210 10:04:20.740631715   22224 pollset_posix.c:586]        poll() failed: Interrupted system call
E1210 10:04:22.805736504   22224 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
E1210 10:04:32.311165691   22224 tcp_client_posix.c:171]     failed to connect to 'ipv4:192.168.122.222:34950': socket error: connection refused
I1210 10:04:36.872827762   22224 completion_queue.c:355]     RETURN_EVENT[0x7f18d328be20]: OP_COMPLETE: tag:0x7f18d2e0fc30 ERROR
IRB::Abort: abort then interrupt!
        from /home/glmatthe/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grpc-0.11.0/lib/grpc/generic/active_call.rb:83:in `call'
        from /home/glmatthe/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grpc-0.11.0/lib/grpc/generic/active_call.rb:83:in `run_batch'
        from /home/glmatthe/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grpc-0.11.0/lib/grpc/generic/active_call.rb:83:in `client_invoke'
        from /home/glmatthe/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grpc-0.11.0/lib/grpc/generic/active_call.rb:458:in `start_call'
        from /home/glmatthe/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grpc-0.11.0/lib/grpc/generic/active_call.rb:378:in `server_streamer'
        from /home/glmatthe/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grpc-0.11.0/lib/grpc/generic/client_stub.rb:327:in `server_streamer'
        from /home/glmatthe/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grpc-0.11.0/lib/grpc/generic/service.rb:189:in `block (3 levels) in rpc_stub_class'

@GuoJing
Copy link

GuoJing commented Jan 14, 2016

Yes, this is a problem, looks like timeout is not working... I don't want my function can't return and always wait for something. If my service is down... my clients may crazy!

For now, I found a simple way to ignore this problem. but I don't know why, I did not look into the code. And this is a really bad code. But it's working.

In python just add a try, except and do nothing:

def run():
    try:
        channel = implementations.insecure_channel('localhost', 50051)
        stub = addressbook_pb2.beta_create_PersonService_stub(channel)
        response = stub.CallPerson(addressbook_pb2.PersonRequest(name='GUOJING'), _TIMEOUT_SECONDS)
        print "Client received: " + response.reply
    except:
        pass

Hope somebody found the reason of this problem. Or grpc is designed for the service which never down?

@danielzohar
Copy link

thanks @GuoJing. However odd, your solution works for me!

@soltanmm
Copy link
Contributor

@GuoJing We handle services that are down; the SIGINT issue is a client-side problem above the layers in which communication occurs. Which version are you using? Do you still have the problem when using context management?

def run():
    channel = implementations.insecure_channel('localhost', 50051)
    with addressbook_pb2.beta_create_PersonService_stub(channel) as stub:
        response = stub.CallPerson(addressbook_pb2.PersonRequest(name='GUOJING'), _TIMEOUT_SECONDS)
    print "Client received: " + response.reply

@GuoJing
Copy link

GuoJing commented Jan 15, 2016

@soltanmm sorry, I delete the comment. You solution is not working, is still get stuck. Ctrl + C.

This is my code:

from grpc.beta import implementations

import addressbook_pb2

_TIMEOUT_SECONDS = 1

def run():
    channel = implementations.insecure_channel('localhost', 50051)
    with addressbook_pb2.beta_create_PersonService_stub(channel) as stub:
        response = stub.CallPerson(addressbook_pb2.PersonRequest(name='GUOJING'), _TIMEOUT_SECONDS)
        print "Greeter client received: " + response.reply

if __name__ == '__main__':
    run()

@soltanmm
Copy link
Contributor

@GuoJing Well, at least that slims down where the problem could be. Will look into it.

@murgatroid99 murgatroid99 self-assigned this Jan 22, 2016
@nicolasnoble nicolasnoble modified the milestones: GA, 2016/05/21 Milestone Apr 21, 2016
@nicolasnoble
Copy link
Member

We've talked about this with @murgatroid99, and this is a simple fix for the ruby code, that he'll implement. Perhaps he can work with @soltanmm or @nathanielmanistaatgoogle to do the same for python.

@viksit
Copy link

viksit commented May 6, 2016

@soltanmm @nathanielmanistaatgoogle @nicolasnoble - any updates on the python side?

@murgatroid99
Copy link
Member

This specific failure, clients locking up/not responding when they are unable to connect to a server should be fixed for all C-based languages, including the 3 tagged here, by the fail-fast default introduced in the latest release. I am going to close this issue for now, and I think we should open up other issues if there are other situations where the library makes a program unresponsive.

@nathanielmanistaatgoogle
Copy link
Member

One such other issue already open is issue 3820 (Python).

@ninagittle
Copy link

ninagittle commented Jun 23, 2016

I'm still getting the same problem with v0.14.1. My code is essentially identical to @GuoJing's (also python) and am getting stuck in when the client becomes unresponsive in exactly the same way. Any idea when you'll have a fix?

E0623 10:14:30.382757362    1545 tcp_client_posix.c:191]     failed to connect to 'ipv4:1.1.1.1:0001': timeout occurred
E0623 10:14:34.495754527    1545 tcp_client_posix.c:191]     failed to connect to 'ipv4:1.1.1.1:0001': timeout occurred
E0623 10:14:40.628632033    1545 tcp_client_posix.c:191]     failed to connect to 'ipv4:1.1.1.1:0001': timeout occurred
E0623 10:14:48.968272253    1545 tcp_client_posix.c:191]     failed to connect to 'ipv4:1.1.1.1:0001': timeout occurred
E0623 10:15:02.203754724    1545 tcp_client_posix.c:191]     failed to connect to 'ipv4:1.1.1.1:0001': timeout occurred

@nathanielmanistaatgoogle
Copy link
Member

@ninagittle: we hope to release 0.15 in the next few days; the problem should already be fixed on master if you're able to work from source.

@ninagittle
Copy link

cheers! looking forward to it

@lock lock bot locked as resolved and limited conversation to collaborators Oct 3, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests