[Varnish] #1683: varnishncsa should log the last value in vcl sub

[Varnish]

#1683: varnishncsa should log the last value in vcl sub
-----------------------+---------------------
 Reporter:  razvanphp  |       Owner:  aondio
     Type:  defect     |      Status:  new
 Priority:  normal     |   Milestone:
Component:  build      |     Version:  4.0.3
 Severity:  normal     |  Resolution:
 Keywords:             |
-----------------------+---------------------

Comment (by razvanphp):

 Sure, here it is:


 {{{
 $ varnishlog
 *   << Request  >> 492374
 -   Begin          req 492373 rxreq
 -   Timestamp      Start: 1425051112.717371 0.000000 0.000000
 -   Timestamp      Req: 1425051112.717371 0.000000 0.000000
 -   ReqStart       82.x.x.x 40912
 -   ReqMethod      GET
 -   ReqURL         /
 -   ReqProtocol    HTTP/1.1
 -   ReqHeader      Host: www.site.com
 -   ReqHeader      Accept:
 text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
 -   ReqHeader      Cookie: sid=76l5ntmd311s12kqbg3jk3j
 -   ReqHeader      User-Agent: Mozilla/5.0 (iPhone; CPU iPhone OS 8_1_3
 like Mac OS X) AppleWebKit/600.1.4 (KHTML, like Gecko) Version/8.0
 Mobile/12B466 Safari/600.1.4
 -   ReqHeader      Accept-Language: en-us
 -   ReqHeader      Accept-Encoding: gzip, deflate
 -   ReqHeader      Connection: keep-alive
 -   ReqHeader      X-Forwarded-For: 82.x.x.x
 -   VCL_call       RECV
 -   ReqHeader      X-Pulse: c11b9f80-be95-11e4-abbd-0fe446ec98be
 -   VCL_acl        NO_MATCH upstream_proxy
 -   ReqUnset       X-Forwarded-For: 82.x.x.x
 -   ReqHeader      X-Forwarded-For: 82.x.x.x
 -   ReqHeader      X-Real-IP: 82.x.x.x
 -   ReqURL         /
 -   ReqHeader      X-UA-Device: desktop
 -   ReqHeader      X-UA-Vendor: generic
 -   ReqUnset       X-UA-Device: desktop
 -   ReqHeader      X-UA-Device: smartphone
 -   ReqUnset       X-UA-Vendor: generic
 -   ReqHeader      X-UA-Vendor: apple
 -   Debug          "VCL_error(702, http://m.site.com/)"
 -   VCL_return     synth
 -   ReqUnset       Accept-Encoding: gzip, deflate
 -   ReqHeader      Accept-Encoding: gzip
 -   VCL_call       HASH
 -   VCL_return     lookup
 -   Timestamp      Process: 1425051112.717628 0.000257 0.000257
 -   RespHeader     Date: Fri, 27 Feb 2015 15:31:52 GMT
 -   RespHeader     Server: Varnish
 -   RespHeader     X-Varnish: 492374
 -   RespProtocol   HTTP/1.1
 -   RespStatus     702
 -   RespReason     Unknown HTTP Status
 -   RespReason     http://m.site.com/
 -   VCL_call       SYNTH
 -   RespHeader     Location: http://m.site.com/
 -   RespStatus     302
 -   RespReason     Found
 -   VCL_return     deliver
 -   RespHeader     Content-Length: 0
 -   Debug          "RES_MODE 2"
 -   RespHeader     Connection: keep-alive
 -   Timestamp      Resp: 1425051112.717689 0.000319 0.000061
 -   ReqAcct        402 0 402 180 0 180
 -   End

 *   << Session  >> 492373
 -   Begin          sess 0 HTTP/1
 -   SessOpen       82.x.x.x 40912 :80 10.107.104.87 80 1425051112.717016
 16
 -   Link           req 492374 rxreq
 -   SessClose      RX_TIMEOUT 5.073
 -   End
 }}}

 In varnishncsa log format I have:

 {{{
 "_remote_device":"%{X-UA-Device}i","_remote_vendor":"%{X-UA-Vendor}i"
 }}}

 and in the log I get


 {{{
 "_remote_device":"desktop","_remote_vendor":"generic"
 }}}

 .. instead of the expected smartphone, apple.

 Before #1462 was solved, I would also get response_status 702, but that is
 fixed now.

-- 
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1683#comment:3>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator