Invalid frame received

[pierre-digimobee]

Hello,

I have an issue beetween haproxy and spoa-mirror :

[ 0][    0.000038]   host: "192.168.10.2", port: "80", path: '^@'
[ 0][    0.000097]   URL: "http://192.168.10.2:80"
[ 0][    0.006566]   setting RLIMIT_NOFILE to 1048576
[ 0][    0.006680]   Server socket created: 5
[ 0][    0.007184]   Server is ready [fragmentation=false - pipelining=false - async=false - debug=true - max-frame-size=16384]
[ 6][    0.007218]   Worker started, thread id: 12
[ 6][    0.007331]   Worker ready to process client messages
[ 7][    0.007350]   Worker started, thread id: 13
[ 7][    0.007415]   Worker ready to process client messages
[ 5][    0.007432]   Worker started, thread id: 11
[ 5][    0.007497]   Worker ready to process client messages
[ 8][    0.007515]   Worker started, thread id: 14
[ 8][    0.007581]   Worker ready to process client messages
[ 4][    0.007601]   Worker started, thread id: 10
[ 4][    0.007664]   Worker ready to process client messages
[ 9][    0.007682]   Worker started, thread id: 15
[ 9][    0.007750]   Worker ready to process client messages
[10][    0.007767]   Worker started, thread id: 16
[10][    0.007828]   Worker ready to process client messages
[ 3][    0.007846]   Worker started, thread id: 9
[ 3][    0.007924]   Worker ready to process client messages
[ 2][    0.007943]   Worker started, thread id: 8
[ 2][    0.008034]   Worker ready to process client messages
[ 1][    0.008052]   Worker started, thread id: 7
[ 1][    0.008113]   Worker ready to process client messages
[ 0][  159.854883]   <1> New client connection accepted and assigned to worker 01
[ 0][  159.854940]   <1> New read event added to worker 01
[ 1][  159.855031]   <1:26> --> Receiving data
[ 1][  159.855038]   <1:26> 4/4/4 byte(s) received frame length
[ 1][  159.855043]   <1:26> 129/129/129 byte(s) received frame data
[ 1][  159.855051]   <1:26> New frame of 129 bytes received: <0100000001000012737570706f727465642d76657273696f6e730803322e300e6d61782d6672616d652d73697a6503fcf0060c6361706162696c69746965730810706970656c696e696e672c6173796e6309656e67696e652d6964082445454643444645352d444244442d343346432d414137342d454238443731373546363243> <........supported-versions..2.0.max-frame-size.....capabilities..pipelining,async.engine-id.$EEFCDFE5-DBDD-43FC-AA74-EB8D7175F62C>
[ 1][  159.855055]   <1> --> HAPROXY-HELLO decoding frame
[ 1][  159.855061]   <1> --> HAPROXY-HELLO header 1 0x01000000 0 0
[ 1][  159.855064]   <1> --> HAPROXY-HELLO stream-id=0 - frame-id=0
[ 1][  159.855066]   <1> K/V item: key=supported-versions
[ 1][  159.855076]   <1> --> HAPROXY-HELLO supported versions: 2.0
[ 1][  159.855078]   <1> K/V item: key=max-frame-size
[ 1][  159.855080]   <1> --> HAPROXY-HELLO maximum frame size: 16380
[ 1][  159.855081]   <1> K/V item: key=capabilities
[ 1][  159.855083]   <1> --> HAPROXY-HELLO capabilities check: pipelining,async
[ 1][  159.855088]   <1> --> HAPROXY-HELLO capabilities set: pipelining  
[ 1][  159.855091]   <1> (E) Failed to decode K/V item
[ 1][  159.855092]   <1> K/V item: key=^Ppipelin
[ 1][  159.855093]   <1> Skip K/V item: key=^Ppipelin
[ 1][  159.855095]   <1:26> (E) Failed to decode HELLO frame
[ 1][  159.855097]   <1> <-- AGENT-DISCONNECT encoding frame
[ 1][  159.855100]   <1> <-- AGENT-DISCONNECT stream-id=0 - frame-id=0
[ 1][  159.855101]   <1> <-- AGENT-DISCONNECT status code: 4
[ 1][  159.855103]   <1> <-- AGENT-DISCONNECT message: invalid frame received
[ 1][  159.855111]   <1:26> <-- Sending data
[ 1][  159.855113]   <1:26> <-- Sending data
[ 1][  159.855122]   <1:26> 4/4/4 byte(s) send frame length
[ 1][  159.855132]   <1:26> 53/53/53 byte(s) send frame data
[ 1][  159.855136]   <1:26> Frame of 53 bytes sent: <660000000100000b7374617475732d636f64650304076d6573736167650816696e76616c6964206672616d65207265636569766564> <f.......status-code...message..invalid frame received>
[ 1][  159.855138]   <1:26> Release client

I use this to do the test :

$ cat Dockerfile
FROM ubuntu:bionic
RUN apt update && apt install -y autoconf automake build-essential git libcurl4-openssl-dev libev-dev libpthread-stubs0-dev pkg-config
WORKDIR /build
COPY . .
RUN ./scripts/bootstrap
RUN ./configure --enable-debug
RUN make all
ENTRYPOINT ./src/spoa-mirror -r0 -u "http://192.168.10.2:80/"
$ docker build -t spoa-mirror .
$ docker run --network=host --rm --name spoa-mirror -d spoa-mirror:latest
$ cd ..
$ docker run --network=host --rm --name my-running-haproxy -v $(pwd)/haproxy:/usr/local/etc/haproxy:ro -d haproxy:latest

And I follow this guide for the configuration : https://www.haproxy.com/blog/haproxy-traffic-mirroring-for-real-world-testing/

[mirror]
spoe-agent mirror
    log global
    messages mirror
    use-backend mirroragents
    timeout hello 500ms
    timeout idle 5s
    timeout processing 5s

spoe-message mirror
    args arg_method=method arg_path=url arg_ver=req.ver arg_hdrs=req.hdrs_bin arg_body=req.body
    event on-frontend-http-request

The weird thing is, when I test on another computer (also with docker), it's working :

[ 4][  632.317522]   <4:26> New frame of 123 bytes received: <0100000001000012737570706f727465642d76657273696f6e730803322e300e6d61782d6672616d652d73697a6503fcf0060c6361706162696c6974696573080a706970656c696e696e6709656e67696e652d6964082443423139423243322d444235432d343244442d393134312d463232453231374543383737> <........supported-versions..2.0.max-frame-size.....capabilities..pipelining.engine-id.$CB19B2C2-DB5C-42DD-9141-F22E217EC877>
[ 4][  632.317538]   <4> --> HAPROXY-HELLO decoding frame
[ 4][  632.317545]   <4> --> HAPROXY-HELLO header 1 0x01000000 0 0
[ 4][  632.317547]   <4> --> HAPROXY-HELLO stream-id=0 - frame-id=0
[ 4][  632.317549]   <4> K/V item: key=supported-versions
[ 4][  632.317552]   <4> --> HAPROXY-HELLO supported versions: 2.0
[ 4][  632.317553]   <4> K/V item: key=max-frame-size
[ 4][  632.317555]   <4> --> HAPROXY-HELLO maximum frame size: 16380
[ 4][  632.317556]   <4> K/V item: key=capabilities
[ 4][  632.317558]   <4> --> HAPROXY-HELLO capabilities check: pipelining
[ 4][  632.317559]   <4> --> HAPROXY-HELLO capabilities set: pipelining  
[ 4][  632.317560]   <4> K/V item: key=engine-id
[ 4][  632.317562]   <4> --> HAPROXY-HELLO engine id: CB19B2C2-DB5C-42DD-9141-F22E217EC877
[ 4][  632.317566]   <4> <-- AGENT-HELLO encoding frame
[ 4][  632.317571]   <4> <-- AGENT-HELLO stream-id=0 - frame-id=0
[ 4][  632.317572]   <4> <-- AGENT-HELLO version: 2.0
[ 4][  632.317573]   <4> <-- AGENT-HELLO maximum frame size: 16380
[ 4][  632.317574]   <4> <-- AGENT-HELLO capabilities: 
[ 4][  632.317581]   <4:26> <-- Sending data
[ 4][  632.317582]   <4:26> <-- Sending data
[ 4][  632.317664]   <4:26> 4/4/4 byte(s) send frame length
[ 4][  632.317684]   <4:26> 54/54/54 byte(s) send frame data
[ 4][  632.317688]   <4:26> Frame of 54 bytes sent: <650000000100000776657273696f6e0803322e300e6d61782d6672616d652d73697a6503fcf0060c6361706162696c69746965730800> <e.......version..2.0.max-frame-size.....capabilities..>

Thank you for your help !

[zaga00]

Hello,

the problem is that you probably have the async option enabled in the spoe-agent configuration and spoa-mirror has a bug when checking haproxy capabilities. This was fixed with the last patch (program version 1.2.1).

Thank you for reporting the bug.