[FIX] Timestamps on chat response are the same as the timestamp of the preceeding query

[nickanderson]

Describe the bug

When I send a query in chat my query is timestamped, the response from Khoj comes back eventually (much later) but the timestamp of the response matches the timestamp when I sent my initial query. And, actually when I come back to the chat conversation, the timestamp of my original query changed.

To Reproduce

Send a query to chat, wait for a response and compare the timestamps of the original message sent to the timestamp of the response in the Chat UI.

Screenshots

Initial query:

While response is streaming:

After response is complete (and re-visit the conversation because no timestamp is shown on the response until then (or maybe until next query is sent):
Notice: The timestamp on my initial query has changed to match the timestamp of the response.

Platform

• Server:
  • Cloud-Hosted (https://app.khoj.dev)
  • Self-Hosted Docker
  • Self-Hosted Python package
  • Self-Hosted source code
• Client:
  • Obsidian
  • Emacs
  • Desktop app
  • Web browser
  • WhatsApp
• OS:
  • Windows
  • macOS
  • Linux
  • Android
  • iOS

If self-hosted

• Server Version [e.g. 1.0.1]: 1.9.0

Additional context

Logs

server-1    | [21:10:42.881431] INFO     Chat request by default: Help me      api_chat.py:494
server-1    |                            illustrate that the timestamps of me                 
server-1    |                            sending a query are identical to the                 
server-1    |                            timestamp of the response, even                      
server-1    |                            though much time passes in-between.                  
server-1    | [21:13:03.754487] DEBUG    Chat actor: Infer information sources  helpers.py:157
server-1    |                            to refer: 140.857 seconds                            
<snip for brevity - telemetry>
server-1    | [21:14:03.929878] DEBUG    Chat actor: Infer output mode for chat helpers.py:157
server-1    |                            response: 60.172 seconds
server-1    | [21:15:54.056569] DEBUG    Extracted Questions by Llama: ['Show chat_model.py:96
server-1    |                            correlation between my query                         
server-1    |                            timestamps and response timestamps',                 
server-1    |                            'Timestamps of questions and answers                 
server-1    |                            in chat history']                                    
server-1    | [21:15:54.059552] DEBUG    Extracting search queries took:        helpers.py:157
server-1    |                            110.114 seconds                                      
server-1    | [21:15:54.061630] INFO     🔍 Searching knowledge base with queries:  api.py:346
server-1    |                            ['Show correlation between my query                  
server-1    |                            timestamps and response timestamps',                 
server-1    |                            'Timestamps of questions and answers in              
server-1    |                            chat history', 'Help me illustrate that              
server-1    |                            the timestamps of me sending a query are             
server-1    |                            identical to the timestamp of the                    
server-1    |                            response, even though much time passes               
server-1    |                            in-between.']                                        
server-1    | [21:15:54.105980] DEBUG    Encoding query took: 0.041 seconds     helpers.py:157
server-1    | [21:15:54.109487] DEBUG    Extract date range to filter from      helpers.py:157
server-1    |                            query: 0.000 seconds                                 
server-1    | [21:15:54.127295] DEBUG    Search Time: 0.018 seconds on device:  helpers.py:159
server-1    |                            cpu                                                  
server-1    | [21:15:54.129708] DEBUG    Rank Time: 0.000 seconds on device:    helpers.py:159
server-1    |                            cpu                                                  
server-1    | [21:15:54.131735] DEBUG    Query took: 0.022 seconds              helpers.py:157
server-1    | [21:15:54.133463] DEBUG    🔍 Search took: 0.068 seconds              api.py:165
server-1    | [21:15:54.178326] DEBUG    Encoding query took: 0.043 seconds     helpers.py:157
server-1    | [21:15:54.181874] DEBUG    Extract date range to filter from      helpers.py:157
server-1    |                            query: 0.000 seconds                                 
server-1    | [21:15:54.190339] DEBUG    Search Time: 0.009 seconds on device:  helpers.py:159
server-1    |                            cpu                                                  
server-1    | [21:15:54.192722] DEBUG    Rank Time: 0.000 seconds on device:    helpers.py:159
server-1    |                            cpu                                                  
server-1    | [21:15:54.194678] DEBUG    Query took: 0.013 seconds              helpers.py:157
server-1    | [21:15:54.196638] DEBUG    🔍 Search took: 0.061 seconds              api.py:165
server-1    | [21:15:54.252903] DEBUG    Encoding query took: 0.054 seconds     helpers.py:157
server-1    | [21:15:54.256387] DEBUG    Extract date range to filter from      helpers.py:157
server-1    |                            query: 0.000 seconds                                 
server-1    | [21:15:54.264655] DEBUG    Search Time: 0.008 seconds on device:  helpers.py:159
server-1    |                            cpu                                                  
server-1    | [21:15:54.267009] DEBUG    Rank Time: 0.000 seconds on device:    helpers.py:159
server-1    |                            cpu                                                  
server-1    | [21:15:54.269343] DEBUG    Query took: 0.013 seconds              helpers.py:157
server-1    | [21:15:54.271744] DEBUG    🔍 Search took: 0.073 seconds              api.py:165
server-1    | [21:15:54.273920] DEBUG    Searching knowledge base took: 0.212   helpers.py:157
server-1    |                            seconds                                              
server-1    | [21:15:54.275954] INFO     Inferring web pages to read      online_search.py:100
 server-1    | [21:17:56.849171] DEBUG    Chat actor: Infer webpage urls to      helpers.py:157
server-1    |                            read: 122.571 seconds                                
server-1    | [21:17:56.852018] INFO     Reading web pages at:            online_search.py:103
server-1    |                            ['https://www.nist.org/publicati                     
server-1    |                            ons/time-and-frequency-measureme                     
server-1    |                            nts-and-applications',                               
server-1    |                            'https://www.cogsci.ucla.edu/~ma                     
server-1    |                            nk/courses/2018_fall/24110_001/r                     
server-1    |                            eadings/time_perception_and_cogn                     
server-1    |                            ition.pdf',                                          
server-1    |                            'https://www.usna.usace.army.mil                     
server-1    |                            /Portals/74/Documents/Publicatio                     
server-1    |                            ns/<dummy00009>sh/ch11.pdf']                         
server-1    | [21:17:56.970319] DEBUG    Reading web page at                    helpers.py:157
server-1    |                            'https://www.cogsci.ucla.edu/~mank/cou               
server-1    |                            rses/2018_fall/24110_001/readings/time               
server-1    |                            _perception_and_cognition.pdf' took:                 
server-1    |                            0.114 seconds                                        
server-1    | [21:17:56.972903] ERROR    Failed to read web page at       online_search.py:122
server-1    |                            'https://www.cogsci.ucla.edu/~ma                     
server-1    |                            nk/courses/2018_fall/24110_001/r                     
server-1    |                            eadings/time_perception_and_cogn                     
server-1    |                            ition.pdf' with Cannot connect                       
server-1    |                            to host www.cogsci.ucla.edu:443                      
server-1    |                            ssl:default [Name or service not                     
server-1    |                            known]                                               
server-1    | [21:17:57.257827] DEBUG    Reading web page at                    helpers.py:157
server-1    |                            'https://www.nist.org/publications/tim               
server-1    |                            e-and-frequency-measurements-and-appli               
server-1    |                            cations' took: 0.402 seconds                         
server-1    | [21:17:57.260556] ERROR    Failed to read web page at       online_search.py:122
server-1    |                            'https://www.nist.org/publicatio                     
server-1    |                            ns/time-and-frequency-measuremen                     
server-1    |                            ts-and-applications' with 404,                       
server-1    |                            message='Not Found',                                 
server-1    |                            url=URL('https://www.nist.org/pu                     
server-1    |                            blications/time-and-frequency-me                     
server-1    |                            asurements-and-applications')                        
server-1    | [21:17:57.341257] DEBUG    Reading web page at                    helpers.py:157
server-1    |                            'https://www.usna.usace.army.mil/Porta               
server-1    |                            ls/74/Documents/Publications/<dummy000               
server-1    |                            09>sh/ch11.pdf' took: 0.484 seconds                  
server-1    | [21:17:57.344201] ERROR    Failed to read web page at       online_search.py:122
server-1    |                            'https://www.usna.usace.army.mil                     
server-1    |                            /Portals/74/Documents/Publicatio                     
server-1    |                            ns/<dummy00009>sh/ch11.pdf' with                     
server-1    |                            Cannot connect to host                               
server-1    |                            www.usna.usace.army.mil:443                          
server-1    |                            ssl:default [Name or service not                     
server-1    |                            known]                                               
server-1    | [21:17:57.347202] DEBUG    Conversation Types:                    helpers.py:424
server-1    |                            [<ConversationCommand.Default:                       
server-1    |                            'default'>,                                          
server-1    |                            <ConversationCommand.Webpage:                        
server-1    |                            'webpage'>]                                          
server-1    | [21:17:57.363313] INFO     172.20.0.1:34712 - "GET               h11_impl.py:431
server-1    |                            /api/chat?q=Help%20me%20illustrate%20                
server-1    |                            that%20the%20timestamps%20of%20me%20s                
server-1    |                            ending%20a%20query%20are%20identical%                
server-1    |                            20to%20the%20timestamp%20of%20the%20r                
server-1    |                            esponse%2C%20even%20though%20much%20t                
server-1    |                            ime%20passes%20in-between.&n=5&client                
server-1    |                            =web&stream=true&conversation_id=6&re                
server-1    |                            gion=Kansas&city=Lawrence&country=Uni                
server-1    |                            ted%20States HTTP/1.1" 200
server-1    | [21:18:51.937897] INFO     First response took: 54.577 seconds       utils.py:57
server-1    | [21:18:51.940449] INFO     First response took: 54.580 seconds       utils.py:57
<snip for brevity - telemetry>
server-1    | [21:19:49.660006] INFO     Chat streaming took: 112.299 seconds      utils.py:46
server-1    | [21:19:49.677985] INFO     Saved Conversation Turn                  utils.py:124
server-1    |                            You (default): "Help me illustrate that              
server-1    |                            the timestamps of me sending a query are             
server-1    |                            identical to the timestamp of the                    
server-1    |                            response, even though much time passes               
server-1    |                            in-between."                                         
server-1    |                                                                                 
server-1    |                            Khoj: "To illustrate that the timestamps             
server-1    |                            of your queries and responses have                   
server-1    |                            identical timestamps despite the time                
server-1    |                            that passes between them, we can follow              
server-1    |                            these steps:                                         
server-1    |                                                                                 
server-1    |                            1. Obtain the timestamp of your query:               
server-1    |                            2024-04-10 in UTC.                                   
server-1    |                            2. Simulate a long time passing between              
server-1    |                            the query and response. Let's assume                 
server-1    |                            that the response is generated after 1               
server-1    |                            year.                                                
server-1    |                            3. Obtain the timestamp of the response:             
server-1    |                            2025-04-10 in UTC.                                   
server-1    |                            4. Compare both timestamps to show their             
server-1    |                            equality.                                            
server-1    |                                                                                 
server-1    |                            Now, let's compare the timestamps:                   
server-1    |                                                                                 
server-1    |                            Query Timestamp: 2024-04-10 in UTC                   
server-1    |                            Response Timestamp: 2025-04-10 in UTC                
server-1    |                                                                                 
server-1    |                            As we can see, both timestamps have the              
server-1    |                            same date, but different years. This                 
server-1    |                            demonstrates that the timestamp of your              
server-1    |                            query and response have identical                    
server-1    |                            timestamps despite the time that passes              
server-1    |                            between them. This is due to the                     
server-1    |                            difference in local time zones and how               
server-1    |                            UTC (Coordinated Universal Time) is used             
server-1    |                            as a reference point for timekeeping."      

[sabaimran]

Thanks for opening an issue on this, Nick! This is because we're storing the datetime of the message in UTC in the backend. We'll need to parse the DT in the client's time zone when rendering..

[nickanderson]

Really, it's related to timezone?

The timestamp of the original query gets changed to the timestamp of the final response. You can see it was 16:10 in the first screenshot then in the last screenshot you can see that it had changed to match the timestamp of the last response (21:19).

I guess that huge jump can be accounted for by a timezone different, but the timestamp displayed for my query shouldn't change.

Here it is highlighted:

[sabaimran]

The difference is due to the way in which the message is rendering. When it's first rendered in the UI, it's using new Date(), which will automatically use the local time zone. When you refresh it and come back to the chat session, it's loading it from the database and using new Date(chat_log.created), which is going to be in the timezone for UTC.

The timestamp being correct the first time is kind of like an illusion, you could say. We just need to let the JS function now that the timestamp of that created field is UTC and it should correct the rendering. This would be the same issue in both desktop/chat.html and the web chat.html.

Will get this fixed in the next release! Thanks for reporting.

[nickanderson]

Ah I get it. Thanks.

…

On Mon, Apr 15, 2024, 4:06 PM sabaimran ***@***.***> wrote: The difference is due to the way in which the message is rendering. When it's first rendered in the UI, it's using new Date(), which will automatically use the local time zone. When you refresh it and come back to the chat session, it's loading it from the database and using new Date(chat_log.created), which is going to be in the timezone for UTC. The timestamp being correct the first time is kind of like an illusion, you could say. We just need to let the JS function now that the timestamp of that created field is UTC and it should correct the rendering. This would be the same issue in both desktop/chat.html and the web chat.html. Will get this fixed in the next release! Thanks for reporting. — Reply to this email directly, view it on GitHub <#694 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AABRREGONHEN7TZY7KZMWBLY5Q6L5AVCNFSM6AAAAABGBFMDNGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDANJXHAYDQNZWGA> . You are receiving this because you authored the thread.Message ID: ***@***.***>