Add logs on API

2025-09-02 20:47:04 +09:00
parent a8dc2ba3b1
commit 3b28f49959
3 changed files with 299 additions and 40 deletions
--- a/rog/views_apis/api_play.py
+++ b/rog/views_apis/api_play.py
@ -14,6 +14,7 @@ from django.utils import timezone
 from datetime import datetime
 import uuid
 import time
+from django.http import JsonResponse

 logger = logging.getLogger(__name__)

@ -237,53 +238,85 @@ def start_from_rogapp(request):
    request_time = timezone.now()
    request_id = str(uuid.uuid4())[:8]
    
-    logger.info(f"[COMPETITION_START] 🏁 API Request Started - ID: {request_id}, Time: {request_time}, Client IP: {client_ip}, User: {user_info}")
-    
-    # リクエストからパラメータを取得
-    event_code = request.data.get('event_code')
-    team_name = request.data.get('team_name')
-    latitude = request.data.get('latitude', 0.0)
-    longitude = request.data.get('longitude', 0.0)
-    extra_data = request.data.get('extra_data', {})
-    
-    logger.info(f"[COMPETITION_START] Request parameters - ID: {request_id}, event_code: '{event_code}', team_name: '{team_name}', GPS: ({latitude},{longitude}), user_agent: '{user_agent[:100]}'")
-    
-    # パラメータ検証
-    if not all([event_code, team_name]):
-        logger.warning(f"[COMPETITION_START] ❌ Missing required parameters - ID: {request_id}, event_code: '{event_code}', team_name: '{team_name}', Client IP: {client_ip}")
-        return Response({
-            "status": "ERROR", 
-            "message": "イベントコードとチーム名が必要です"
-        }, status=status.HTTP_400_BAD_REQUEST)
+    # 初期ログ出力
+    logger.info(f"[START_API] 🚀 REQUEST_START - ID: {request_id}")
+    logger.info(f"[START_API] Request details - Time: {request_time}, Client: {client_ip}, User: {user_info}")
+    logger.info(f"[START_API] Headers - User-Agent: {user_agent[:200]}")
+    logger.info(f"[START_API] Content-Type: {request.content_type}")
+    logger.info(f"[START_API] Method: {request.method}")
    
    try:
+        # リクエストデータの解析
+        logger.info(f"[START_API] Raw request body type: {type(request.body)}")
+        logger.info(f"[START_API] Raw request body length: {len(request.body) if request.body else 0}")
+        
+        # リクエストからパラメータを取得
+        logger.info(f"[START_API] Attempting to parse request data...")
+        event_code = request.data.get('event_code')
+        team_name = request.data.get('team_name')
+        latitude = request.data.get('latitude', 0.0)
+        longitude = request.data.get('longitude', 0.0)
+        extra_data = request.data.get('extra_data', {})
+        
+        logger.info(f"[START_API] Parameters parsed - ID: {request_id}")
+        logger.info(f"[START_API] event_code: '{event_code}' (type: {type(event_code)})")
+        logger.info(f"[START_API] team_name: '{team_name}' (type: {type(team_name)})")
+        logger.info(f"[START_API] GPS: lat={latitude}, lon={longitude}")
+        logger.info(f"[START_API] extra_data: {extra_data}")
+        
+        # パラメータ検証
+        if not event_code:
+            logger.warning(f"[START_API] ❌ Missing event_code - ID: {request_id}")
+            return Response({
+                "status": "ERROR", 
+                "message": "イベントコードが必要です"
+            }, status=status.HTTP_400_BAD_REQUEST)
+            
+        if not team_name:
+            logger.warning(f"[START_API] ❌ Missing team_name - ID: {request_id}")
+            return Response({
+                "status": "ERROR", 
+                "message": "チーム名が必要です"
+            }, status=status.HTTP_400_BAD_REQUEST)
+        
+        logger.info(f"[START_API] ✅ Parameter validation passed - ID: {request_id}")
+        
+        # データベース操作開始
+        logger.info(f"[START_API] Starting database operations - ID: {request_id}")
+        
        # イベントの存在確認
+        logger.info(f"[START_API] Searching for event: '{event_code}' - ID: {request_id}")
        event = NewEvent2.objects.filter(event_name=event_code).first()
+        
        if not event:
-            logger.warning(f"[COMPETITION_START] ❌ Event not found - ID: {request_id}, event_code: '{event_code}', Client IP: {client_ip}")
+            logger.warning(f"[START_API] ❌ Event not found - ID: {request_id}, event_code: '{event_code}'")
            return Response({
                "status": "ERROR", 
                "message": "指定されたイベントが見つかりません"
            }, status=status.HTTP_404_NOT_FOUND)
        
-        logger.info(f"[COMPETITION_START] ✅ Event found - ID: {request_id}, Event ID: {event.id}, Name: '{event.event_name}', Start: {event.start_datetime}, End: {event.end_datetime}")
+        logger.info(f"[START_API] ✅ Event found - ID: {request_id}, Event ID: {event.id}, Name: '{event.event_name}'")
+        logger.info(f"[START_API] Event details - Start: {event.start_datetime}, End: {event.end_datetime}")
        
        # チームの存在確認
+        logger.info(f"[START_API] Searching for team: '{team_name}' in event: '{event_code}' - ID: {request_id}")
        entry = Entry.objects.filter(
            event=event, 
            team_name=team_name
        ).first()
        
        if not entry:
-            logger.warning(f"[COMPETITION_START] ❌ Team not found - ID: {request_id}, team_name: '{team_name}', event_code: '{event_code}', Client IP: {client_ip}")
+            logger.warning(f"[START_API] ❌ Team not found - ID: {request_id}, team: '{team_name}', event: '{event_code}'")
            return Response({
                "status": "ERROR", 
                "message": "指定されたチームが見つかりません"
            }, status=status.HTTP_404_NOT_FOUND)
        
-        logger.info(f"[COMPETITION_START] ✅ Team found - ID: {request_id}, Entry ID: {entry.id}, Team: '{team_name}', Zekken: {entry.zekken_number}, Category: '{entry.category.category_name if entry.category else 'N/A'}', Owner: '{entry.owner.email if entry.owner else 'N/A'}')")
+        logger.info(f"[START_API] ✅ Team found - ID: {request_id}, Entry ID: {entry.id}")
+        logger.info(f"[START_API] Team details - Zekken: {entry.zekken_number}, Category: '{entry.category.category_name if entry.category else 'N/A'}'")
        
-        # 既にスタート済みかチェック（GpsLogでSTARTレコードを確認）
+        # 既にスタート済みかチェック
+        logger.info(f"[START_API] Checking if team already started - ID: {request_id}")
        existing_start = GpsLog.objects.filter(
            entry=entry,
            cp_number="START",
@ -291,45 +324,86 @@ def start_from_rogapp(request):
        ).first()
        
        if existing_start:
-            logger.warning(f"[COMPETITION_START] ⚠️  Team already started - ID: {request_id}, team_name: '{team_name}', zekken: {entry.zekken_number}, start_time: {existing_start.checkin_time}, Client IP: {client_ip}")
+            logger.warning(f"[START_API] ⚠️ Team already started - ID: {request_id}, start_time: {existing_start.checkin_time}")
            return Response({
                "status": "WARNING", 
                "message": "このチームは既にスタートしています",
-                "start_time": entry.start_info.start_time.strftime("%Y-%m-%d %H:%M:%S")
+                "start_time": existing_start.checkin_time.strftime("%Y-%m-%d %H:%M:%S")
            })
        
+        logger.info(f"[START_API] ✅ Team not started yet - ID: {request_id}")
+        
        # トランザクション開始
+        logger.info(f"[START_API] Starting database transaction - ID: {request_id}")
        with transaction.atomic():
            # スタート情報をGpsLogとして登録
+            logger.info(f"[START_API] Creating start record - ID: {request_id}")
            start_info = GpsLog.objects.create(
                entry=entry,
-                cp_number="START",  # スタート専用のCP番号
-                serial_number=0,    # スタート記録の固定シリアル番号
-                latitude=latitude if latitude else 0.0,
-                longitude=longitude if longitude else 0.0,
+                cp_number="START",
+                serial_number=0,
+                latitude=float(latitude) if latitude else 0.0,
+                longitude=float(longitude) if longitude else 0.0,
                checkin_time=timezone.now(),
                extra_data=extra_data
            )
            
+            logger.info(f"[START_API] ✅ Start record created - ID: {request_id}, GpsLog ID: {start_info.id}")
+            
            # 統計情報取得
-            total_checkpoints = Location2025.objects.filter(event=event).count() if hasattr(Location2025, 'event') else 0
+            try:
+                total_checkpoints = Location2025.objects.filter(event=event).count()
+                logger.info(f"[START_API] Total checkpoints available: {total_checkpoints} - ID: {request_id}")
+            except Exception as e:
+                logger.warning(f"[START_API] Could not get checkpoint count: {str(e)} - ID: {request_id}")
+                total_checkpoints = 0
            
-            logger.info(f"[COMPETITION_START] 🎉 SUCCESS - ID: {request_id}, Team: '{team_name}', Zekken: {entry.zekken_number}, Event: '{event_code}', Start Time: {start_info.checkin_time}, GPS: ({latitude},{longitude}), Total CPs Available: {total_checkpoints}, Client IP: {client_ip}, User: {user_info}")
-            
-            return Response({
+            # 成功レスポンス準備
+            response_data = {
                "status": "OK", 
                "message": "スタート処理が完了しました",
                "team_name": team_name,
                "event_code": event_code,
-                "start_time": start_info.start_time.strftime("%Y-%m-%d %H:%M:%S")
-            })
+                "start_time": start_info.checkin_time.strftime("%Y-%m-%d %H:%M:%S"),
+                "zekken_number": entry.zekken_number,
+                "entry_id": entry.id
+            }
+            
+            logger.info(f"[START_API] 🎉 SUCCESS - ID: {request_id}, Team: '{team_name}', Zekken: {entry.zekken_number}")
+            logger.info(f"[START_API] Response data: {response_data}")
+            
+            return Response(response_data)
    
    except Exception as e:
-        logger.error(f"[COMPETITION_START] 💥 CRITICAL ERROR - ID: {request_id}, team_name: '{team_name}', event_code: '{event_code}', Client IP: {client_ip}, Error: {str(e)}", exc_info=True)
-        return Response({
-            "status": "ERROR", 
-            "message": "サーバーエラーが発生しました"
-        }, status=status.HTTP_500_INTERNAL_SERVER_ERROR)
+        # 詳細なエラー情報をログに出力
+        logger.error(f"[START_API] 💥 CRITICAL ERROR - ID: {request_id}")
+        logger.error(f"[START_API] Error type: {type(e).__name__}")
+        logger.error(f"[START_API] Error message: {str(e)}")
+        logger.error(f"[START_API] Request data: event_code='{event_code if 'event_code' in locals() else 'UNDEFINED'}', team_name='{team_name if 'team_name' in locals() else 'UNDEFINED'}'")
+        logger.error(f"[START_API] Client: {client_ip}, User: {user_info}")
+        logger.error(f"[START_API] Full traceback:", exc_info=True)
+        
+        # エラーレスポンス
+        try:
+            return Response({
+                "status": "ERROR", 
+                "message": "サーバーエラーが発生しました",
+                "error_id": request_id
+            }, status=status.HTTP_500_INTERNAL_SERVER_ERROR)
+        except Exception as response_error:
+            logger.error(f"[START_API] 💥 DOUBLE ERROR - Could not create error response: {str(response_error)}")
+            # 最後の手段として、シンプルなJSONレスポンスを返す
+            return JsonResponse({
+                "status": "ERROR", 
+                "message": "サーバーエラーが発生しました",
+                "error_id": request_id
+            }, status=500)
+    
+    finally:
+        # 処理完了ログ
+        end_time = timezone.now()
+        duration = (end_time - request_time).total_seconds()
+        logger.info(f"[START_API] 🏁 REQUEST_END - ID: {request_id}, Duration: {duration:.3f}s")
    

 """