These are chat archives for fanout/pushpin

19th
Jun 2017
Francis Eytan Dortort
@dortort
Jun 19 2017 13:19

@jkarneges Here's what appears in m2adapter.log:

[DEBUG] 2017-06-19 08:01:15.224 m2: IN pushpin-m2-7999 618481 / 231:{"PATH":"/","connection":"close","DOWNLOAD_CREDITS":"102400","user-agent":"ELB-HealthChecker/2.0","host":"172.31.59.151","METHOD":"GET","VERSION":"HTTP/1.1","URI":"/","PATTERN":"/","URL_SCHEME":"http","REMOTE_ADDR":"172.31.16.207"},0:,
[INFO] 2017-06-19 08:01:15.224 IN pushpin-m2-7999 id=618481 GET http://172.31.59.151/
[DEBUG] 2017-06-19 08:01:15.225 zhttp: OUT T322:3:seq,1:0#6:stream,4:true!4:body,0:,12:peer-address,13:172.31.16.207,7:headers,97:22:10:Connection,5:close,]24:4:Host,13:172.31.59.151,]39:10:User-Agent,21:ELB-HealthChecker/2.0,]]4:from,9:m2zhttp_9,3:ext,15:5:multi,4:true!}6:method,3:GET,7:credits,6:102400#3:uri,21:http://172.31.59.151/,2:id,24:pushpin-m2-7999_618481_0,}
[DEBUG] 2017-06-19 08:01:15.225 zhttp: IN T116:2:id,24:pushpin-m2-7999_618481_0,3:seq,1:0#4:from,16:pushpin-proxy_11,4:type,10:keep-alive,3:ext,15:5:multi,4:true!}}
[DEBUG] 2017-06-19 08:01:15.253 zhttp: IN T225:2:id,24:pushpin-m2-7999_618481_0,3:seq,1:1#7:headers,61:30:12:Content-Type,10:text/plain,]23:14:Content-Length,2:32,]]4:from,16:pushpin-proxy_11,4:body,32:Error while proxying to origin.
,4:code,3:502#6:reason,11:Bad Gateway,}
[DEBUG] 2017-06-19 08:01:15.253 zhttp: id=pushpin-m2-7999_618481_0 response data size=32
[INFO] 2017-06-19 08:01:15.253 OUT pushpin-m2-7999 id=618481 code=502 32
[DEBUG] 2017-06-19 08:01:15.253 m2: OUT [pushpin-m2-7999 6:618481, HTTP/1.1 502 Bad Gateway
Content-Type: text/plain
Content-Length: 32
Connection: close

]
[DEBUG] 2017-06-19 08:01:15.254 m2: OUT [pushpin-m2-7999 6:618481, Error while proxying to origin.
]
[DEBUG] 2017-06-19 08:01:15.254 request id=pushpin-m2-7999_618481_0 written 32 (no flow control)
[DEBUG] 2017-06-19 08:01:15.254 zhttp: OUT instance=pushpin-proxy_11 T93:3:seq,1:1#4:from,9:m2zhttp_9,4:type,6:credit,7:credits,2:32#2:id,24:pushpin-m2-7999_618481_0,}
[DEBUG] 2017-06-19 08:01:15.254 m2: OUT [pushpin-m2-7999 6:618481, ]
[DEBUG] 2017-06-19 08:01:15.254 m2: IN pushpin-m2-7999 618481 @* 41:{"METHOD":"JSON","DOWNLOAD_CREDITS":"93"},18:{"type":"credits"},
[DEBUG] 2017-06-19 08:01:15.254 m2: OUT [pushpin-m2-7999 8:X 618481, 26:3:ctl,16:6:cancel,4:true!}]]
[DEBUG] 2017-06-19 08:01:15.254 m2: IN pushpin-m2-7999 618481 @* 41:{"METHOD":"JSON","DOWNLOAD_CREDITS":"32"},18:{"type":"credits"},
[DEBUG] 2017-06-19 08:01:15.254 m2: OUT [pushpin-m2-7999 8:X 618481, 26:3:ctl,16:6:cancel,4:true!}]]
[DEBUG] 2017-06-19 08:01:15.254 m2: IN pushpin-m2-7999 618481 @* 17:{"METHOD":"JSON"},21:{"type":"disconnect"},
[DEBUG] 2017-06-19 08:01:15.254 m2: pushpin-m2-7999 id=618481 disconnected
[DEBUG] 2017-06-19 08:01:15.254 m2: IN pushpin-m2-7999 618481 @* 17:{"METHOD":"JSON"},21:{"type":"disconnect"},
[DEBUG] 2017-06-19 08:01:15.254 m2: pushpin-m2-7999 id=618481 disconnected
[DEBUG] 2017-06-19 08:01:15.255 zhttp: IN T76:2:id,24:pushpin-m2-7999_618481_0,4:from,16:pushpin-proxy_11,4:type,6:cancel,}
[DEBUG] 2017-06-19 08:01:15.255 zhttp: received message for unknown request id, canceling

The service appears to still be running (since it's logging) but isn't functional, ie. it no longer proxies responses.

Francis Eytan Dortort
@dortort
Jun 19 2017 13:31
Is the issue possibly being caused by the ELB health check requests?
Justin Karneges
@jkarneges
Jun 19 2017 16:51
@dortort let's see zurl.log
if it turns out this is related to IP addresses changing, I made a fix for that recently. but I would think an ELB IP change would be very rare or nonexistent if throughput doesn't change
Francis Eytan Dortort
@dortort
Jun 19 2017 18:28
Justin Karneges
@jkarneges
Jun 19 2017 18:35
looks like it tries to contact two different IPs, both which result in ssl errors
and all you do is restart pushpin and it works again? does zurl.log show different IPs being used after the restart?
Francis Eytan Dortort
@dortort
Jun 19 2017 18:36
and neither of which are the current IPs of the ELB
I haven't restarted this time yet. Would you like me to restart one particular service?
Justin Karneges
@jkarneges
Jun 19 2017 18:41
you could try restarting just zurl if that's possible. it's set up as a separate service on debian/ubuntu. but if it's being managed by the pushpin runner then it won't be possible and you'll have to restart everything. but that's okay
Francis Eytan Dortort
@dortort
Jun 19 2017 19:45
restarting pushpin didn't help, still used the cached IPs. Restarting the container fixed the issue.
Any way of preventing the use of curl's cache?
Justin Karneges
@jkarneges
Jun 19 2017 20:08
zurl/curl caching is in memory only, so a restart would have cleared it
if the whole container required a restart then maybe there is something on the container doing caching like dnsmasq?
Justin Karneges
@jkarneges
Jun 19 2017 20:15
another test you could try (next time) is shelling into the container and resolving the domain using ping or dig to see if you get the new or old IP
Francis Eytan Dortort
@dortort
Jun 19 2017 22:27
How can I try out your recent changes?