Improve raidpicture.php error handling & logging (pokepark#224)

* Document & make use of new info_log() to help troubleshoot issues

- Info level logging is enabled by default since it has very low
verbosity except in cases that probably deserve poking into.
- Update a few logging calls to info_log() as an example.

* Add error handling & logging to raidpicture, fallback pokemon icon

- Use the new info_log() to provide useful hints when pokemon icons are
missing
- Revamp fallback image handling so that even unknown raid levels get at
least some icon, avoiding spurious errors
- Icon is under the Pixabay License: https://pixabay.com/vectors/pokemon-pokemon-go-pikachu-figure-1574006/

README.md

@@ -91,7 +91,7 @@ Telegram webhook bot for organizing raids in Pokemon Go. Developers are welcome
          * [translate.py](#translatepy)
             * [Usage](#usage)
 
-<!-- Added by: artanicus, at: Wed Mar  3 19:34:56 EET 2021 -->
+<!-- Added by: artanicus, at: Tue Mar 16 21:46:59 EET 2021 -->
 
 <!--te-->
 
@@ -1206,18 +1206,20 @@ Updates to the config file are NOT checked automatically. Therefore always check
 | CURL_USEPROXY| Bool, enable curl via proxy |
 | DB_HOST | Host or ip address of MySQL server |
 | DB_NAME | Name of DB |
-| DB_PASSWORD | Password of dedicated RaidBot DB user|
-| DB_USER | Username of dedicated RaidBot DB user|
+| DB_PASSWORD | Password of dedicated RaidBot DB user |
+| DB_USER | Username of dedicated RaidBot DB user |
 | DDOS_MAXIMUM | ? |
-| DEBUG | Output helpful debugging messages to `DEBUG_LOGFILE`|
-| DEBUG_LOGFILE | Full path to debug logfile|
+| DEBUG | Output helpful debugging messages to `DEBUG_LOGFILE` |
+| DEBUG_LOGFILE | Full path to debug logfile |
 | DEBUG_INCOMING | Also log details on incoming webhook data to separate file, quite verbose! |
 | DEBUG_INCOMING_LOGFILE | Full path to incoming data debug logfile|
 | DEBUG_SQL | Also log details on DB queries to separate file, quite verbose! |
 | DEBUG_SQL_LOGFILE | Full path to SQL debug logfile|
 | DEFAULTS_WARNING | json files don't support comments, this is just a comment warning you not to edit defaults. |
 | LANGUAGE_PRIVATE| Language to use in private messages. Leave empty to infer language from users Telegram language |
 | LANGUAGE_PUBLIC| Language to use in groups |
+| LOGGING_INFO | Log INFO level messages to the file defined by LOGGING_INFO_LOGFILE. Useful for identifying potential issues. |
+| LOGGING_INFO_LOGFILE | Path to logfile. |
 | MAINTAINER_ID| Telegram ID of main maintainer |
 | MAINTAINER| Name of main maintainer |
 | MAPS_API_KEY| Google Maps API key for `MAPS_LOOKUP` |

VERSION

@@ -1 +1 @@
-2.1.074.2
+2.1.075.3

commands/raid_from_webhook.php

@@ -40,14 +40,14 @@ function isPointInsidePolygon($point, $polygon) {
     $exclude_raid_levels = explode(',', $config->WEBHOOK_EXCLUDE_RAID_LEVEL);
     $exclude_pokemons = explode(',', $config->WEBHOOK_EXCLUDE_POKEMON);
     if ((!empty($level) && in_array($level, $exclude_raid_levels)) || (!empty($pokemon) && in_array($pokemon, $exclude_pokemons))) {
-        debug_log($pokemon,'Ignoring raid, the pokemon is excluded:');
+        info_log($pokemon,'Ignoring raid, the pokemon is excluded:');
         continue;
     }
 
     // Create gym if not exists
     $gym_name = $raid['message']['name'];
     if ($config->WEBHOOK_EXCLUDE_UNKNOWN && $gym_name === "unknown") {
-        debug_log($raid['message']['gym_id'],'Ignoring raid, the gym name is unknown and WEBHOOK_EXCLUDE_UNKNOWN says to ignore. id:');
+        info_log($raid['message']['gym_id'],'Ignoring raid, the gym name is unknown and WEBHOOK_EXCLUDE_UNKNOWN says to ignore. id:');
         continue;
     }
     $gym_lat = $raid['message']['latitude'];
@@ -79,7 +79,7 @@ function isPointInsidePolygon($point, $polygon) {
             }
         }
         if ($insideGeoFence === false) {
-            debug_log($gym_name,'Ignoring raid, not inside geofence:');
+            info_log($gym_name,'Ignoring raid, not inside geofence:');
             continue;
         }
     }
@@ -342,7 +342,7 @@ function isPointInsidePolygon($point, $polygon) {
 
     // Skip posting if create only -mode is set or raid time is greater than value set in config
     if ($config->WEBHOOK_CREATE_ONLY or ($end_timestamp-$start_timestamp) > ($config->WEBHOOK_EXCLUDE_AUTOSHARE_DURATION * 60) ) {
-        debug_log($gym_name,'Not autoposting raid, its duration is over the WEBHOOK_EXCLUDE_AUTOSHARE_DURATION threshold:');
+        info_log($gym_name,'Not autoposting raid, its duration is over the WEBHOOK_EXCLUDE_AUTOSHARE_DURATION threshold:');
         continue;
     }
 

config/config.json.example

@@ -1,5 +1,5 @@
 {
-  "VERSION":"2.1.074.2",
+  "VERSION":"2.1.075.3",
   "DB_HOST":"localhost",
   "DB_NAME":"your_database_name",
   "DB_USER":"your_database_user",

config/defaults-config.json

@@ -4,10 +4,12 @@
   "DB_NAME":"PokemonRaidBot",
   "DB_USER":"PokemonRaidBot",
   "DB_PASSWORD":"",
+  "LOGGING_INFO": true,
+  "LOGGING_INFO_LOGFILE": "/var/log/tg-bots/raid-bot.log",
   "DEBUG": false,
-  "DEBUG_LOGFILE":"/var/log/tg-bots/dev-raid-bot.log",
+  "DEBUG_LOGFILE":"/var/log/tg-bots/raid-bot.log",
   "DEBUG_INCOMING": false,
-  "DEBUG_INCOMING_LOGFILE":"/var/log/tg-bots/dev-raid-bot-incoming.log",
+  "DEBUG_INCOMING_LOGFILE":"/var/log/tg-bots/raid-bot-incoming.log",
   "DEBUG_SQL": false,
   "DEBUG_SQL_LOGFILE":"/var/log/tg-bots/dev-raid-bot-sql.log",
   "APIKEY_HASH":"",
@@ -62,12 +64,13 @@
   "RAID_PICTURE_ICONS_WHITE": true,
   "RAID_PICTURE_FILE_FORMAT":"gif",
   "RAID_PICTURE_SHOW_SHINY": true,
-  "RAID_DEFAULT_PICTURE":"https://example.com/raid/default_picture.jpg",
+  "RAID_DEFAULT_PICTURE":"images/gym_default.png",
   "RAID_PICTURE_URL":"https://example.com/raid/raidpicture.php",
   "RAID_PICTURE_FONT_GYM":"NotoSans-Bold.ttf",
   "RAID_PICTURE_FONT_EX_GYM":"NotoSans-Regular.ttf",
   "RAID_PICTURE_FONT_TEXT":"NotoSans-Regular.ttf",
   "RAID_PICTURE_POKEMON_ICONS":"pokemon,PokeMiners,ZeChrales",
+  "RAID_PICTURE_POKEMON_FALLBACK":"images/shadow_pika.png",
   "RAID_POLL_UI_ORDER":"extra,teamlvl,time,pokemon,status",
   "RAID_POLL_HIDE_USERS_TIME":"10",
   "RAID_POLL_HIDE_BUTTONS_RAID_LEVEL":"1,2,3",

logic/get_raid_level.php

@@ -25,7 +25,7 @@ function get_raid_level($pokedex_id, $pokemon_form_id)
         }
         debug_log("Resolved level of {$pokedex_id}({$pokemon_form_id}) to {$raid_level}");
     } else {
-        debug_log("Could not resolve level of {$pokedex_id}({$pokemon_form_id}), defaulting to 0!");
+        info_log("Could not resolve level of {$pokedex_id}({$pokemon_form_id}), defaulting to 0!");
         $raid_level = '0';
     }
 

mods/edit_save.php

@@ -65,7 +65,7 @@
         include_once($module);
         exit();
     } else {
-        debug_log('Error! Fast forward failed as file does not exist!');
+        info_log($module, 'Error! Fast forward failed as file does not exist:');
         exit();
     }
 }

raidpicture.php

@@ -1,27 +1,35 @@
 <?php
 
-// Parent dir.
 $parent = __DIR__;
 
 // Include requirements and perfom initial steps
 include_once(__DIR__ . '/core/bot/requirements.php');
-
-// Database connection
 include_once(CORE_BOT_PATH . '/db.php');
-
-// Get language
 include_once(CORE_BOT_PATH . '/userlanguage.php');
 
+// Create GD image object from given URI regardless of file type
+function grab_img($uri){
+  $img = imagecreatefromstring(file_get_contents($uri));
+  if ($img === false) {
+    info_log($uri, 'Failed to get image:');
+    return false;
+  }
+  return $img;
+}
+
 // Debug switch
 $debug = false;
 if(isset($_GET['debug']) && $_GET['debug'] == 1) {
     $debug = true;
 }
 
 // Raid info
-$raid_id = preg_replace("/\D/","",$_GET['raid']);
-if($_GET['raid']!="") {
+if(array_key_exists('raid', $_GET) && $_GET['raid']!="") {
+    $raid_id = preg_replace("/\D/","",$_GET['raid']);
     $raid = get_raid_with_pokemon($raid_id);
+} else {
+  info_log('Called without a raid id, things will fail');
+  $raid = null;
 }
 
 // Fonts
@@ -44,6 +52,8 @@
 $config_bg_color = explode(',',$config->RAID_PICTURE_BG_COLOR);
 if(count($config_bg_color) == 3) {
     $bg_rgb = $config_bg_color;
+} else {
+  info_log($config->RAID_PICTURE_BG_COLOR, 'Invalid value RAID_PICTURE_BG_COLOR:');
 }
 $bg_color = imagecolorallocate($canvas,$bg_rgb[0],$bg_rgb[1], $bg_rgb[2]);
 imagefill($canvas, 0, 0, $bg_color);
@@ -54,6 +64,8 @@
 $config_font_color = explode(',',$config->RAID_PICTURE_TEXT_COLOR);
 if(count($config_font_color) == 3) {
     $font_rgb = $config_font_color;
+} else {
+  info_log($config->RAID_PICTURE_TEXT_COLOR, 'Invalid value RAID_PICTURE_TEXT_COLOR:');
 }
 $font_color = imagecolorallocate($canvas,$font_rgb[0],$font_rgb[1],$font_rgb[2]);
 
@@ -62,12 +74,17 @@
 $transparent_rgb = [0,255,0];
 
 // Gym image
-if (!empty($raid['img_url'])) {
-    $img_gym = imagecreatefromjpeg($raid['img_url']);
-} else if(is_file($config->RAID_DEFAULT_PICTURE)) {
-    $img_gym = imagecreatefromjpeg($config->RAID_DEFAULT_PICTURE);
+$gym_url = $raid['img_url'];
+if (!empty($gym_url)) {
+  $img_gym = grab_img($gym_url);
 } else {
-    $img_gym = imagecreatefrompng(IMAGES_PATH . "/gym_default.png");
+    info_log('No gym img_url given, using default gym image');
+    if(is_file($config->RAID_DEFAULT_PICTURE)) {
+      $img_gym = grab_img($config->RAID_DEFAULT_PICTURE);
+    } else {
+        info_log($config->RAID_DEFAULT_PICTURE, 'Cannot read default gym image:');
+        $img_gym = grab_img(IMAGES_PATH . "/gym_default.png");
+    }
 }
 
 // Get the width and height of the gym picture
@@ -118,8 +135,8 @@
 if($raid['ex_gym'] == 1) {
     $ex_text_size = 20;
     $ex_text_angle = 0;
-    $corner = 16;										// Roundness of the corners
-    $extra = $ex_text_size/5+1;							// Some extra height
+    $corner = 16; // Roundness of the corners
+    $extra = $ex_text_size/5+1; // Some extra height
 
     $ex_mark_bg_color = [94,169,190];
     $ex_mark_text_color = [255,255,255];
@@ -181,7 +198,7 @@
     // Raid Egg
     if($raid['pokedex_id'] > 9990) {
         // Getting the actual icon
-        $img_pokemon = imagecreatefrompng(IMAGES_PATH . "/raid_eggs/pokemon_icon_" . $raid['pokedex_id'] . "_00.png");
+        $img_pokemon = grab_img(IMAGES_PATH . "/raid_eggs/pokemon_icon_" . $raid['pokedex_id'] . "_00.png");
 
         // Position and size of the picture
         $dst_x = $dst_y = 150;
@@ -200,10 +217,8 @@
         }
         $p_icon = $p_icon . ".png";
 
-        // Initialize pokemon image with egg image (+ used as fallback if no pokemon image was found)
-        $img_file = IMAGES_PATH . "/raid_eggs/pokemon_icon_999" . $raid['raid_level'] . "_00.png";
-
         // Check pokemon icon source and create image
+        $img_file = null;
         $p_sources = explode(',', $config->RAID_PICTURE_POKEMON_ICONS);
         foreach($p_sources as $p_dir) {
             // Set pokemon icon dir
@@ -213,16 +228,28 @@
             if($p_dir == 'pokemon') {
                 $p_img = IMAGES_PATH . "/pokemon/" . $p_icon;
             }
-
-            // Make sure file exists
-            if (file_exists($p_img) && filesize($p_img) > 0) {
+            // Check if file exists in this collection
+            if(file_exists($p_img) && filesize($p_img) > 0) {
                 $img_file = $p_img;
                 break;
             }
         }
 
-        // Create image
-        $img_pokemon = imagecreatefrompng($img_file);
+        // If no image was found, substitute with a fallback
+        if($img_file === null) {
+          info_log($p_icon, 'Failed to find an image in any pokemon image collection for:');
+          $img_fallback_file = null;
+          // If we know the raid level, fallback to egg image
+          if(array_key_exists('raid_level', $raid) && $raid['raid_level'] !== null && $raid['raid_level'] != 0) {
+            $img_fallback_file = IMAGES_PATH . "/raid_eggs/pokemon_icon_999" . $raid['raid_level'] . "_00.png";
+          } else {
+            info_log('Unknown raid level, using fallback icon.');
+            $img_fallback_file = $config->RAID_PICTURE_POKEMON_FALLBACK;
+          }
+          $img_file = $img_fallback_file;
+        }
+
+        $img_pokemon = grab_img($img_file);
 
         // Position and size of the picture
         $dst_x = $dst_y = 100;
@@ -232,7 +259,7 @@
 // Raid ended
 } else {
     // Raid won image
-    $img_pokemon = imagecreatefrompng(IMAGES_PATH . "/raidwon.png");
+    $img_pokemon = grab_img(IMAGES_PATH . "/raidwon.png");
 
     // Position and size of the picture
     $dst_x = $dst_y = 172;
@@ -259,7 +286,7 @@
 
 // Ex-Raid?
 if($raid['raid_level'] == 'X') {
-    $img_expass = imagecreatefrompng(IMAGES_PATH . "/expass.png");
+    $img_expass = grab_img(IMAGES_PATH . "/expass.png");
     imagesavealpha($img_expass,true);
 
     // Debug - Add border around expass image
@@ -274,12 +301,12 @@
 
 
 // Adding the gym name to the image
-$text_size = 23;									// Font size of additional text
-$text_size_cp_weather = 20;									// Font size of weather cp text
+$text_size = 23; // Font size of additional text
+$text_size_cp_weather = 20;// Font size of weather cp text
 $left_after_poke = 356; // First left position behind the pokemon icon.
-$angle = 0;											// Angle of the text
-$spacing = 10;										// Spacing between lines
-$spacing_right = 10;								// Empty space on the right for weather icons and CP text
+$angle = 0; // Angle of the text
+$spacing = 10; // Spacing between lines
+$spacing_right = 10; // Empty space on the right for weather icons and CP text
 
 
 
@@ -306,7 +333,6 @@
 // Wrap gym name to multiple lines if too long
 $gym_name_lines = explode(PHP_EOL,wordwrap(trim($gym_name),($gym_name_total_chars+$gym_name_word_largest)/$gym_name_rows,PHP_EOL));
 
-// Write to log.
 debug_log($gym_name_total_chars, 'Gym name length:');
 debug_log($gym_name_lines, 'Gym name lines:');
 
@@ -486,7 +512,7 @@
         if($config->RAID_PICTURE_ICONS_WHITE) {
             $weather_icon_path = IMAGES_PATH . "/weather_white/";
         }
-        $weather_icon = imagecreatefrompng($weather_icon_path . $we . ".png"); // 64x64
+        $weather_icon = grab_img($weather_icon_path . $we . ".png"); // 64x64
         imagecopyresampled($canvas,$weather_icon,$canvas_width-$spacing_right-($count_weather-$i)*40,$poke_text_top-30,0,0,38,38,64,64);
     }
 }