Search code examples
javascriptreactjscorsfastapiuvicorn

FastAPI POST endpoint runs 4 times per single POST request


When running my FastAPI server, I have a POST endpoint that, for some reason, runs 4 times per POST request.

FastAPI backend code:

app = FastAPI()
app.add_middleware(
    CORSMiddleware,
    allow_origins=origins,
    allow_credentials=True,
    allow_methods=["*"],
    allow_headers=["*"],
)
[...]
@app.post("/create_new_session")
async def create_session(session_id: str, user_id: int = -1):
    create_new_session(session_id, user_id)
    logger.info(
        "created new session", extra={"session_id": session_id, "user_id": user_id}
    )

React frontend code:

function APP():
  [...]
  useEffect(() => {
    const dontUseSessionIdCookie = process.env.REACT_APP_DONT_USE_USER_ID_COOKIE === "true";
    datadogLogs.logger.info(`using session_id cookie: ${!dontUseSessionIdCookie}`, {'session-id': sessionId})
    const foundSessionId = dontUseSessionIdCookie ? undefined : Cookies.get('session_id');
    if (foundSessionId) {
      setSessionId(foundSessionId);
    } else {
      const sessionId = uuidv4();
      datadogLogs.logger.info('New session started', {'session-id': sessionId});  // Logs a new UUID
      Cookies.set('session_id', sessionId, { expires: 7 });
      setSessionId(sessionId);
      fetch(`${api_server_url}/create_new_session?session_id=${sessionId}`, {
        method: 'POST',
        redirect: 'follow',
      })
        .then(response => response.json())
        .then(data => datadogLogs.logger.info('Created new session', { 'data': data, 'session-id': sessionId }))
        .catch((error) => {
          datadogLogs.logger.error('Error while creating a new session:', { 'error': error, 'session-id': sessionId });
        });
    }
  }, [])

To be sure there was only one post request I've captured all HTTP traffic in Wireshark, and indeed saw only one request. When inserting a breakpoint at the BE entrypoint I see the same src port for the request, the same session-id, and differences of ~800ms between calls. This happens both locally, and when we run in production (over Herkou).

Any ideas?? Thanks :D

I've inspected both the frontend and backend logs and saw that there was indeed one log from the frontend and 4 logs from the backend. I used wireshark to make sure there wasnt some retry logic I wasnt aware of. I've inserted breakpoints in the entry point and manually inspected each ingress request to try and find clues.


Solution

  • This was actually a problem with the logger, and not the FastAPI endpoint. The problem with the logger is a dup of this thread: Python logging module is printing lines multiple times