search

startersclan / source-udp-forwarder

A simple HTTP and UDP forwarder to the HLStatsX:CE daemon. Supports Counter-Strike 2. Dockerized šŸ³
Apache License 2.0
4 stars 2 forks source link

MALFORMED DATA #47

Closed theck1 closed 10 months ago

theck1 commented 10 months ago

Hi. I run a CS2 server egg in pterodactyl and trying to make hlstatsx:ce work on my dedicated server.

In the daemon log I get: 2023-12-06 00:34:00: 192.168.1.188:27060 - E998: MALFORMED DATA: L 12/06/2023 - 00:33:52.509 - "sv_vote_issue_kick_allowed" = "true"

Get a lot of E998: MALFORMED data.

I have tried MariaDB and MySQL 5.7, no change.

HLSTatsX webpage seems to register the server a bit, it shows the time it has been online, but not much more.

Any help is apprechiated.

My docker-compose:

version: '2.2'
services:
  # 2. source-udp-forwarder proxy forwards gameserver logs to the daemon
  # See: https://github.com/startersclan/source-udp-forwarder
  source-udp-forwarder:
    image: startersclan/source-udp-forwarder:latest
    environment:
      - UDP_LISTEN_ADDR=0.0.0.0:26999
      - UDP_FORWARD_ADDR=daemon:27500
      - FORWARD_PROXY_KEY=#SECRET# # The daemon's proxy_key secret
      - FORWARD_GAMESERVER_IP=192.168.1.188 # The gameserver's IP as registered in the HLStatsX:CE database
      - FORWARD_GAMESERVER_PORT=27060 # The gameserver's IP as registered in the HLStatsX:CE database
      - LOG_LEVEL=INFO
      - LOG_FORMAT=txt
    volumes:
      - dns-volume:/dns
    ports:
      - 26999:26999
    networks:      
      - default
    depends_on:
      - daemon
    entrypoint:
      - /bin/sh
    command:
      - -c
      - |
          set -eu

          echo "Outputting my IP address"
          ip addr show eth0 | grep 'inet ' | awk '{print $$2}' | cut -d '/' -f1 | tee /dns/source-udp-forwarder

          exec /source-udp-forwarder

  # 3. HLStatsX:CE perl daemon accepts the gameserver logs. Gameserver Logs are parsed and stats are recorded
  # The daemon's proxy_key secret can only be setup in the HLStatsX:CE Web Admin Panel Settings under 'Proxy Settings' section
  daemon:
    image: startersclan/hlstatsx-community-edition:1.10.0-daemon
    ports:
      - 27500:27500/udp   # For external servers to send logs to the daemon    
    depends_on:
      - db
    command:
      - --ip=0.0.0.0
      - --port=27500
      - --db-host=172.19.0.2:3306
      - --db-name=hlxce
      - --db-username=hlxce
      - --db-password=hlxce
      - --nodns-resolveip
      - --debug
      # - --debug
      # - --help

  # Cron - awards
  awards:
    image: startersclan/hlstatsx-community-edition:1.10.0-daemon
    stop_signal: SIGKILL
    entrypoint:
      - /bin/sh
    command:
      - -c
      - |
          set -eu

          echo "Creating /awards.sh"
          cat - > /awards.sh <<'EOF'
          #!/bin/sh
          set -eu
          cd /scripts
          perl hlstats-awards.pl --db-host=db:3306 --db-name=hlstatsxce --db-username=hlstatsxce --db-password=hlstatsxce #--help
          EOF
          chmod +x /awards.sh

          # Run at 00:00 daily. To customize your cron schedule, use https://crontab.guru
          echo "Creating crontab"
          crontab - <<'EOF'
          PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
          0 0 * * * /awards.sh > /proc/1/fd/1 2>/proc/1/fd/2
          EOF
          crontab -l

          echo "Running cron"
          cron -f

  # 4. HLStatsX:CE DB
  # db:
  #   image: mysql:5.7
  #   environment:
  #     - MYSQL_ROOT_PASSWORD=root    # Username 'root', password 'root'
  #     - MYSQL_USER=hlstatsxce
  #     - MYSQL_PASSWORD=hlstatsxce
  #     - MYSQL_DATABASE=hlstatsxce
  #   ports:
  #     - 3305:3305
  #   volumes:
  #     - db-volume:/var/lib/mysql
  #     - ./src/sql/install.sql:/docker-entrypoint-initdb.d/install.sql:ro  # This seeds the DB only on the first time,

  db:
    image: mariadb:5
    networks: 
      - default
    environment:
      - MYSQL_USER=hlxce
      - MYSQL_PASSWORD=hlxce
      - MYSQL_DATABASE=hlxce
      - MYSQL_ROOT_PASSWORD=hlxce
    ports:
      - 3305:3305
    volumes:    
      - mysql:/var/lib/mysql

  # 5. HLStatsX:CE web
  # Available at http://localhost:8081, or https://web.example.com
  # Admin Panel username: admin, password: 123456
  web:
    image: startersclan/hlstatsx-community-edition:1.10.0-web    
    volumes:
      - games-volume:/web/hlstatsimg/games  # Stateful games volume, which also contains heatmaps
    environment:
      - DB_ADDR=172.19.0.2:3306
      - DB_NAME=hlxce
      - DB_USER=hlxce
      - DB_PASS=hlxce
      - DB_DEBUG=0
    ports:
      - 8081:80
      - 9000
    depends_on:
      - init-container

  # Cron - Heatmaps
  heatmaps:
    image: startersclan/hlstatsx-community-edition:1.10.0-web
    volumes:
      - games-volume:/web/hlstatsimg/games  # Stateful games volume, which also contains heatmaps
    environment:
      - DB_HOST=192.168.1.188
      - DB_NAME=hlxce
      - DB_USER=hlxce
      - DB_PASS=hlxce
      - HLXCE_WEB=/web
      - HUD_URL=#secret#
      - OUTPUT_SIZE=medium
      - DEBUG=1
    depends_on:
      - init-container
      - web
    working_dir: /heatmaps
    stop_signal: SIGKILL
    entrypoint:
      - /bin/sh
    command:
      - -c
      - |
          set -eu

          # Run at 00:00 daily. To customize your cron schedule, use https://crontab.guru
          echo "Creating crontab"
          crontab - <<'EOF'
          0 0 * * * php /heatmaps/generate.php > /proc/1/fd/1 2>/proc/1/fd/2
          EOF
          crontab -l

          echo "Running crond"
          exec crond -f

  # PHPMyAdmin to manage DB
  # Available at http://localhost:8083, or https://phpmyadmin.example.com
  phpmyadmin:
    image: phpmyadmin:5.2
    environment:
      - PMA_HOST=db
    ports:
      - 8083:80

  # Init container to set permissions in mounted folders and volumes
  init-container:
    image: alpine:latest
    volumes:
      - db-volume:/var/lib/mysql
    networks:      
      - default
    entrypoint:
      - /bin/sh
    command:
      - -c
      - |
          set -eu

          echo "Granting db write permissions"
          chown -R 999:999 /var/lib/mysql

volumes:
  dns-volume:
  db-volume:
  games-volume:
  mysql:
leojonathanoh commented 10 months ago

Hey @theck1, you are right, it's because the daemon doesn't yet support the cs2 log format. I've got it figured in my personal fork. Let me open a PR for the daemon to fix the logs for CS2, which should in principle work.

leojonathanoh commented 10 months ago

You can track the progress in https://github.com/startersclan/hlstatsx-community-edition/pull/41. Once i think it's ready I will release šŸ˜„

leojonathanoh commented 10 months ago

It works well, I've released v1.11.0 https://github.com/startersclan/hlstatsx-community-edition/releases, hope it works out for you šŸ˜„.

For cs2, follow the commented out section in docker-compose.yml

theck1 commented 10 months ago

It works well, I've released v1.11.0 https://github.com/startersclan/hlstatsx-community-edition/releases, hope it works out for you šŸ˜„.

For cs2, follow the commented out section in docker-compose.yml

Thank you so much for the quick reply.

That worked much better, maps show up and everything. But when loading a map my hlstats daemon shuts down:

daemon_1                | 2023-12-06 11:03:52:   192.168.1.188:27060 - E019: Started map ""
daemon_1                | 2023-12-06 11:03:52:   192.168.1.188:27060 - PROXY: L 12/06/2023 - 11:03:48.261 - "DemoRecorder<0><BOT><>" connected, address "none"
daemon_1                | 2023-12-06 11:03:52:   192.168.1.188:27060 - E001: (IGNORED) BOT: "DemoRecorder" <P:3,U:-1,W:BOT:e138aaddc050473ea9ef4e655cba1cce,T:> connected, address "none", hostname "", hostgroup ""
daemon_1                | 2023-12-06 11:03:52:   192.168.1.188:27060 - PROXY: L 12/06/2023 - 11:03:48.261 - "DemoRecorder<0><UNKNOWN><>" entered the game
daemon_1                | Can't call method "set" on unblessed reference at .//HLstats_EventHandlers.plib line 564.
hlstatsce_daemon_1 exited with code 255
leojonathanoh commented 10 months ago

Hmm, thought I fixed that bug, let me check again šŸ˜„

leojonathanoh commented 10 months ago

Hey @theck1, releaseed v1.11.1 https://github.com/startersclan/hlstatsx-community-edition/releases please try it šŸ˜„

gnoffer commented 8 months ago

Hi, unfortunately I have to get in touch on this again. I think I have everything up to date and correct, but I still get the message with E998: MALFORMED DATA:

i am running cs2 on baremetal, logging to localhost docker container with your source-udp-forwarder

> root@cs2:/opt/cs2# cat docker-compose.yml
> version: '3.7'
> services:
>   source-udp-forwarder:
>     image: startersclan/source-udp-forwarder:latest
>     environment:
>       - LISTEN_ADDR=:26999
>       - UDP_FORWARD_ADDR=192.168.222.89:27500
>       - FORWARD_PROXY_KEY=x
>       - FORWARD_GAMESERVER_IP=192.168.222.183
>       - FORWARD_GAMESERVER_PORT=27015
>       - LOG_LEVEL=DEBUG
>       - LOG_FORMAT=txt
>     volumes:
>       - dns-volume:/dns
>     ports:
>       - 26999:26999/tcp
>       - 26999:26999/udp
>     restart: unless-stopped
> 
> volumes:
>   dns-volume:
>

Log:

ime="2024-01-25T13:33:43Z" level=debug msg="[HTTP] Received log from 192.168.222.183:47401. buf length: 115, string: 01/25/2024 - 14:33:42.801 - \"McC4mpser<0><[U:1:5443070]><TERRORIST>\" [-441 1049 -63] committed suicide with \"world\""
time="2024-01-25T13:33:43Z" level=debug msg="[HTTP] Prepending 'L ' to log line"
time="2024-01-25T13:33:43Z" level=debug msg="[HTTP] prepend len: 64, string: PROXY Key=x192.168.222.183:27015PROXY L "
time="2024-01-25T13:33:43Z" level=debug msg="[HTTP] Prepending prepend to buf"
time="2024-01-25T13:33:43Z" level=debug msg="[HTTP] newbuf len: 179, string: PROXY Key=x192.168.222.183:27015PROXY L 01/25/2024 - 14:33:42.801 - \"McC4mpser<0><[U:1:5443070]><TERRORIST>\" [-441 1049 -63] committed suicide with \"world\""
time="2024-01-25T13:33:43Z" level=debug msg="Reusing existing client connection: [::]:56294"

which forwards udp logs to a vm with hlxce and udp daemon

Error:

2024-01-25 14:33:38: 192.168.222.183:27015 - E998: MALFORMED DATA: L 01/25/2024 - 14:33:38.444 - "McC4mpser<0><[U:1:5443070]><TERRORIST>" [-441 1049 -63] killed "Orlo<3><BOT><CT>" [-424 61 -1] with "ak47" (headshot)

What the hell i am doing wrong ?

ive used everything from https://github.com/startersclan/hlstatsx-community-edition/tree/master/src

theck1 commented 8 months ago

Hi, unfortunately I have to get in touch on this again. I think I have everything up to date and correct, but I still get the message with E998: MALFORMED DATA:

What worked for me when I got that error was updating all the hlstats containers AND the source-udp-forwarder container :)

gnoffer commented 8 months ago

thanks, buti am running source-udp-forwarder container in Version 0.3.0 and copied hlstsxce here from repo, so actually 1.11.2 !? so should be ok - i hope

gnoffer commented 8 months ago

ok, now i got a step further.... i used also daemon as docker container with

 daemon:
    image: startersclan/hlstatsx-community-edition:1.11.2-daemon
    ports:
      - 27500:27500/udp   # For external servers to send logs to the daemon
    command:
      - --ip=0.0.0.0
      - --port=27500
      - --db-host=192.168.222.89:3306
      - --db-name=hlxce
      - --db-username=hlxce
      - --db-password=xxxx
      - --nodns-resolveip
      - --debug

instead of the execuatble within scripts folder. now the error is gone, but when i join the server the container exits with last log:

Can't call method "set" on unblessed reference at .//HLstats_EventHandlers.plib line 564.

when i restart the container while i am on the server, it keeps running, but only sees BOTs and not seeing/measuring me.

any tipps on this ? it is the same error as you had @theck1

gnoffer commented 8 months ago

ive now added restart: unless-stopped so itworks a bit. but the first person who joins the server brings daemon to crash. after it restartet automatically all other users expect of the first one will be counted.

leojonathanoh commented 8 months ago

Could you post the daemon logs when it crashes? It's an error very similar to https://github.com/startersclan/hlstatsx-community-edition/pull/44. Are you using source2mod or some mod by any chance? Those might also need to be accounted for in the daemon code, not just DemoRecorder.

gnoffer commented 8 months ago

there isnt a lot in there:

2024-02-01 20:01:56: 192.168.222.183:27015 - PROXY: L 02/01/2024 - 21:01:55.389 - World triggered "Round_Start"
2024-02-01 20:01:56: 192.168.222.183:27015 - E013: (IGNORED) NOTMINPLAYERS: World triggered "Round_Start" (0/2)
2024-02-01 20:01:56: 192.168.222.183:27015 - PROXY: L 02/01/2024 - 21:01:55.436 - rcon from "172.18.0.3:57474": command "say HLstatsX:CE disabled! Need at least 2 active players (0/2)"
2024-02-01 20:01:56: 192.168.222.183:27015 - E020: OK Rcon from "172.18.0.3": "say HLstatsX:CE disabled! Need at least 2 active players (0/2)"
2024-02-01 20:01:56: 192.168.222.183:27015 - PROXY: L 02/01/2024 - 21:01:55.451 - "Console<0>" say "HLstatsX:CE disabled! Need at least 2 active players (0/2)"
2024-02-01 20:01:56: 192.168.222.183:27015 - E014: () say "HLstatsX:CE disabled! Need at least 2 active players (0/2)"
2024-02-01 20:01:56: 192.168.222.183:27015 - PROXY: L 02/01/2024 - 21:01:56.842 - "X<0><[U:Y]><>" STEAM USERID validated
2024-02-01 20:01:56: 192.168.222.183:27015 - E001: BAD DATA: "X<0><[U:Y]><>" STEAM USERID validated
2024-02-01 20:02:01: 192.168.222.183:27015 - PROXY: L 02/01/2024 - 21:02:01.253 - "X<0><[U:Y]><>" entered the game
Can't call method "set" on unblessed reference at .//HLstats_EventHandlers.plib line 564.
2024-02-01 20:02:02:                       - MYSQL: Connecting to MySQL database 'hlxce' on '192.168.222.89:3306' as user 'hlxce' ... connected ok
2024-02-01 20:02:02:                       - CONFIG: Reading database config...
2024-02-01 20:02:02:                       - CONFIG: I have found the following server configs in database:
2024-02-01 20:02:02:                       - S_CONFIG: 192.168.222.183:27015
2024-02-01 20:02:02:                       - HLSTATSX: HLstatsX:CE 1.11.2 starting...
2024-02-01 20:02:02:                       - UDP: Opening UDP listen socket on 0.0.0.0:27500 ... ok
2024-02-01 20:02:02:                       - HLSTATSX: Tracking Trend of the stats are enabled
2024-02-01 20:02:02:                       - HLSTATSX: Maximum Skill Change on all servers are 25 points
2024-02-01 20:02:02:                       - HLSTATSX: Minimum Skill Change on all servers are 5 points
2024-02-01 20:02:02:                       - HLSTATSX: Minimum Players Kills on all servers are 50 kills
2024-02-01 20:02:02:                       - HLSTATSX: Players chat logging is enabled
2024-02-01 20:02:02:                       - HLSTATSX: Admins chat logging is enabled
2024-02-01 20:02:02:                       - HLSTATSX: Broadcasting public chat is disabled
2024-02-01 20:02:02:                       - HLSTATSX: Event queue size is set to 10
2024-02-01 20:02:02:                       - HLSTATSX: HLstatsX:CE is now running (Normal mode, debug level 1)
2024-02-01 20:02:12: 192.168.222.183:27015 - PROXY: L 02/01/2024 - 21:02:12.170 - "Sails<1><BOT><>" entered the game
2024-02-01 20:02:12: 192.168.222.183:27015 - SERVER: Connecting to rcon on 192.168.222.183:27015 ... ok
2024-02-01 20:02:12: 192.168.222.183:27015 - TRCON: Trying to get rcon access (auth)
2024-02-01 20:02:12: 192.168.222.183:27015 - TRCON: Rcon password accepted
2024-02-01 20:02:13: 192.168.222.183:27015 - SERVER: Server running map: de_mirage
leojonathanoh commented 8 months ago

@gnoffer looking at the logs the error of interest is seen:

2024-02-01 20:02:01: 192.168.222.183:27015 - PROXY: L 02/01/2024 - 21:02:01.253 - "X<0><[U:Y]><>" entered the game
Can't call method "set" on unblessed reference at .//HLstats_EventHandlers.plib line 564.

It occurs because the human player X is assigned $userid is 0 by the gameserver, and that is actually invalid (as it has always been in steam games; only bots are assigned userid 0). Hence, it's really actually bad logging on the part of the gameserver. One way to solve this is to make 0 "valid" only when the player is a non-bot, by giving it a random value larger than 0, such as 1, but which however may clash with the next joining player for which the gameserver may assign userid of 1.

If I get the time to be able to get a familiar with the code perhaps I'd be able to push a fix. But for a hotfix, let me open a PR now, you can try to bind mount the hlstats.pl file in the daemon container and see if it works.

leojonathanoh commented 8 months ago

@gnoffer if it's possible could I request you open an issue on https://github.com/startersclan/hlstatsx-community-edition, with a reference to this issue, so we can resume the discussion there, since this crash is not caused by source-udp-forwarder.

gnoffer commented 8 months ago

done.

leojonathanoh commented 8 months ago

Let me push it :)