COOP potentially not respecting garbage collection of time-limited fact-statements

[ross-spencer]

Given a fact statement with the "finite" timestamp: 1691357772 which is 7-days in the future at the time of writing. It can be observed in the coop-state:

      },
      "fd'fsId": "30344341303036313535314244313445",
      "fs'gcAfter": {
        "contents": {
          "getPOSIXTime": 1691357772
        },
        "tag": "Finite"
      },
      "fs'submitter": {
        "getPubKeyHash": "bedfff1b6762f7a95437ab8ca30b3244dfe44029125d23656062a8b6"
      }

But, a call to garbage collect fact statement succeeds - possibly incorrectly, but the use of the feature may be incorrect:

}
info {
  tx_builder_info {
    obsolete_fs_ids: "04CA00E6A0A5C68E"
    obsolete_fs_ids: "04CA0061551BD14E"
    valid_fs_ids: "04CA000ACC65CA96"
  }
}

2023-07-30 21:42:17 INFO :: py_publish.py:328:gc_txs() :: newly obsoleted statements: 2
2023-07-30 21:42:17 INFO :: py_publish.py:329:gc_txs() :: items not found: 0

04CA0061551BD14E shows up as obsoleted. 04CA000ACC65CA96 is marked POS_INF.

State timestamp shows up as:

  ],                                                                                                                                                                   
  "cs'currentTime": [                                                                                                                                                  
    {                                                                                                                                                                  
      "getPOSIXTime": 1690753658000                                                                                                                                    
    },                                                                                                                                                                 
    {                                                                                                                                                                  
      "getPOSIXTime": 1690753659000                                                                                                                                    
    }                                                                                                                                                                  
  ],   

[bladyjoker]

Hey @ross-spencer I can't really understand what went wrong from what you posted. Concretely, I don't see the 7-day long FactStatement before and after the GC. Perhaps posting before and after state information would make things more clear?

I'd even suggest replicating this by using the Tutorial steps.

[ross-spencer]

Thanks @bladyjoker please find the datum here on preprod: https://preprod.cexplorer.io/datum/d6a1afc8527b1ac39cadb15e7ce3fab93ab7a16b249a4283cefb7dd532776380 - it still has six days before it should be retired :wink: -- I'm using a grpc call to store the fact per the spec. It seems to me finnite timestamps aren't respected. There aren't docs in the tutorial about what to expect there and so perhaps there's some more information that can be elaborated on here?

[bladyjoker]

Hey @ross-spencer , Cardano browsers/explorers are the worst things, I can't parse anything from there.

I would like to know where the FactStatement UTxO that has been retired before its time is, can you point me at it?

[ross-spencer]

I only have my phone on me but it was spent the very next Tx. This should be the ID you want? It has the two reference inputs that were spent including the one we're talking about.

https://preprod.cexplorer.io/tx/f6613727527d1c26c9ea6ee58494acd21ebf83b690ea1112114b313afb1ff6f0

[bladyjoker]

You're right @ross-spencer there's something fishy here!

[bladyjoker]

@ross-spencer added another summary of the issue in https://github.com/mlabs-haskell/cardano-open-oracle-protocol/issues/76#issuecomment-1677228195

[bladyjoker]

Where the magic happens

https://github.com/mlabs-haskell/cardano-open-oracle-protocol/blob/60bd6bd2f3ef2bad2c1a25c55272d2fe0424316e/coop-pab/src/Coop/Pab.hs#L661

https://github.com/mlabs-haskell/cardano-open-oracle-protocol/blob/60bd6bd2f3ef2bad2c1a25c55272d2fe0424316e/coop-plutus/src/Coop/Plutus.hs#L66

[ross-spencer]

@bladyjoker I think I have fixed this...

Sometime 21 August -> 1692632273000 (milliseconds) Also, sometime 21 August -> 1692632273 (seconds)

Python is returning a timestamp in seconds which looks just fine to other parsers. Plutus is probably evaluating it to 1970 or something...

So, to pass the datetime to the grpc call to create the transaction a user has to take Python's call to datetime and times it by 1000 to turn it into milliseconds:

E.g.

fact_statement["gcAfter"] = { "extended": "FINITE", "finite_ledger_time": (t+604800)*1000 }

I'll do a bit more testing to make sure this is right, but it looks promising after garbage collection locally:

2023-08-14 15:47:49 INFO :: py_publish.py:212:call_get_state() :: calling `coop-pab-cli get-state --any-wallet 6c94dbe282700e1bfe8b6159f0d7a2574e2a26748c6ee8d03067d346`
2023-08-14 15:47:53 INFO :: py_publish.py:227:call_get_state() :: calling `coop-pab-cli` a success
2023-08-14 15:47:53 INFO :: py_publish.py:180:_process_state_json_for_fact_ids() :: total '2' fact statements in the store
2023-08-14 15:47:53 INFO :: py_publish.py:202:_process_state_json_for_fact_ids() :: fact statement ids on-chain: [FactData(id='04CA000ACC65CA96', time_limit='PosInf', timestamp=None, timestamp_human=None), FactData(id='04CA007ACD75D2C7', time_limit='Finite', timestamp=1692632273000, timestamp_human='2023-08-21T15:37:53Z')]
2023-08-14 15:47:53 INFO :: py_publish.py:409:batch_gc() :: Collecting IDs: [b'04CA000ACC65CA96', b'04CA007ACD75D2C7']
2023-08-14 15:47:53 INFO :: py_publish.py:444:gc_txs() :: certificate file location: /home/orcfax/git/mlabs/coop.0/.coop-publisher-cli/certificate.pem
2023-08-14 15:47:53 INFO :: py_publish.py:120:tls_credentials() :: certificate file location: /home/orcfax/git/mlabs/coop.0/.coop-publisher-cli/certificate.pem
2023-08-14 15:47:53 INFO :: py_publish.py:132:submitter() :: submitting Tx as: bedfff1b6762f7a95437ab8ca30b3244dfe44029125d23656062a8b6
2023-08-14 15:47:57 INFO :: py_publish.py:458:gc_txs() :: error {
  tx_builder_err {
    other_err {
      msg: "Failed creating a gc-fact-statement-tx"
    }
  }
}
info {
  tx_builder_info {
    valid_fs_ids: "04CA000ACC65CA96"
    valid_fs_ids: "04CA007ACD75D2C7"
  }
}

local datum ids on chain:                                                                                                                                              
{                                                                                                                                                                      
  "facts": [                                                                                                                                                           
    [
      "04CA000ACC65CA96",
      "PosInf",
      null,
      null
    ],
    [
      "04CA007ACD75D2C7",
      "Finite",
      1692632273000,
      "2023-08-21T15:37:53Z"
    ]
  ],
  "total": 2
}

If it sounds like you are expecting milliseconds, then my providing seconds was probably the problem here.

In terms of "fixes" I can probably write some docs here too. Not sure if there are any other subtleties around data types that need discussing? but might think about that too.

[bladyjoker]

Great find! I was doing deep testing today, and couldn't reproduce it directly at the Plutus level. I suspected something like this being an issue. Can you document that also at https://github.com/mlabs-haskell/cardano-open-oracle-protocol/blob/60bd6bd2f3ef2bad2c1a25c55272d2fe0424316e/coop-proto/cardano.proto#L29?

[ross-spencer]

Looks like that was it! This fact expired after ten minutes and the scripts did their job and prevented collection before then.

2023-08-14 16:34:13 INFO :: py_publish.py:212:call_get_state() :: calling `coop-pab-cli get-state --any-wallet 6c94dbe282700e1bfe8b6159f0d7a2574e2a26748c6ee8d03067d346
`                                                                                                                                                                      
2023-08-14 16:34:18 INFO :: py_publish.py:227:call_get_state() :: calling `coop-pab-cli` a success                                                                     
2023-08-14 16:34:18 INFO :: py_publish.py:180:_process_state_json_for_fact_ids() :: total '3' fact statements in the store                                             
2023-08-14 16:34:18 INFO :: py_publish.py:202:_process_state_json_for_fact_ids() :: fact statement ids on-chain: [FactData(id='04CA000ACC65CA96', time_limit='PosInf', 
timestamp=None, timestamp_human=None), FactData(id='04CA007ACD75D2C7', time_limit='Finite', timestamp=1692632273000, timestamp_human='2023-08-21T15:37:53Z'), FactData(
id='04CA00D571634792', time_limit='Finite', timestamp=1692031015000, timestamp_human='2023-08-14T16:36:55Z')]                                                          
2023-08-14 16:34:18 INFO :: py_publish.py:409:batch_gc() :: Collecting IDs: [b'04CA000ACC65CA96', b'04CA007ACD75D2C7', b'04CA00D571634792']                            
2023-08-14 16:34:18 INFO :: py_publish.py:444:gc_txs() :: certificate file location: /home/orcfax/git/mlabs/coop.0/.coop-publisher-cli/certificate.pem                 
2023-08-14 16:34:18 INFO :: py_publish.py:120:tls_credentials() :: certificate file location: /home/orcfax/git/mlabs/coop.0/.coop-publisher-cli/certificate.pem        
2023-08-14 16:34:18 INFO :: py_publish.py:132:submitter() :: submitting Tx as: bedfff1b6762f7a95437ab8ca30b3244dfe44029125d23656062a8b6                                
2023-08-14 16:34:22 INFO :: py_publish.py:458:gc_txs() :: error {                                                                                                      
  tx_builder_err {                                                                                                                                                     
    other_err {                                                                                                                                                        
      msg: "Failed creating a gc-fact-statement-tx"                                                                                                                    
    }                                                                                                                                                                  
  }                                                                                                                                                                    
}                                                                                                                                                                      
info {                                                                                                                                                                 
  tx_builder_info {                                                                                                                                                    
    valid_fs_ids: "04CA000ACC65CA96"                                                                                                                                   
    valid_fs_ids: "04CA007ACD75D2C7"                                                                                                                                   
    valid_fs_ids: "04CA00D571634792"                                                                                                                                   
  }                                                                                                                                                                    
}                                                                                                                                                                      

2023-08-14 16:34:22 INFO :: py_publish.py:467:gc_txs() :: newly obsoleted statements: 0                                                                                
2023-08-14 16:34:22 INFO :: py_publish.py:468:gc_txs() :: items not found: 0    
2023-08-14 16:37:45 INFO :: py_publish.py:212:call_get_state() :: calling `coop-pab-cli get-state --any-wallet 6c94dbe282700e1bfe8b6159f0d7a2574e2a26748c6ee8d03067d346
`                                                                                                                                                                      
2023-08-14 16:37:50 INFO :: py_publish.py:227:call_get_state() :: calling `coop-pab-cli` a success                                                                     
2023-08-14 16:37:50 INFO :: py_publish.py:180:_process_state_json_for_fact_ids() :: total '3' fact statements in the store                                             
2023-08-14 16:37:50 INFO :: py_publish.py:202:_process_state_json_for_fact_ids() :: fact statement ids on-chain: [FactData(id='04CA000ACC65CA96', time_limit='PosInf', 
timestamp=None, timestamp_human=None), FactData(id='04CA007ACD75D2C7', time_limit='Finite', timestamp=1692632273000, timestamp_human='2023-08-21T15:37:53Z'), FactData(
id='04CA00D571634792', time_limit='Finite', timestamp=1692031015000, timestamp_human='2023-08-14T16:36:55Z')]                                                          
local datum ids on chain:                                                                                                                                              
{                                                                                                                                                                      
  "facts": [                                                                                                                                                           
    [                                                                                                                                                                  
      "04CA000ACC65CA96",                                                                                                                                              
      "PosInf",                                                                                                                                                        
      null,                                                                                                                                                            
      null                                                                                                                                                             
    ],                                                                                                                                                                 
    [                                                                                                                                                                  
      "04CA007ACD75D2C7",                                                                                                                                              
      "Finite",                                                                                                                                                        
      1692632273000,                                                                                                                                                   
      "2023-08-21T15:37:53Z"                                                                                                                                           
    ],                                                                                                                                                                 
    [                                                                                                                                                                  
      "04CA00D571634792",                                                                                                                                              
      "Finite",                                                                                                                                                        
      1692031015000,                                                                                                                                                   
      "2023-08-14T16:36:55Z"                                                                                                                                           
    ]                                                                                                                                                                  
  ],                                                                                                                                                                   
  "total": 3                                                                                                                                                           
} 
2023-08-14 16:38:00 INFO :: py_publish.py:212:call_get_state() :: calling `coop-pab-cli get-state --any-wallet 6c94dbe282700e1bfe8b6159f0d7a2574e2a26748c6ee8d03067d346
`                                                                                                                                                                      
2023-08-14 16:38:05 INFO :: py_publish.py:227:call_get_state() :: calling `coop-pab-cli` a success                                                                     
2023-08-14 16:38:05 INFO :: py_publish.py:180:_process_state_json_for_fact_ids() :: total '3' fact statements in the store                                             
2023-08-14 16:38:05 INFO :: py_publish.py:202:_process_state_json_for_fact_ids() :: fact statement ids on-chain: [FactData(id='04CA000ACC65CA96', time_limit='PosInf', 
timestamp=None, timestamp_human=None), FactData(id='04CA007ACD75D2C7', time_limit='Finite', timestamp=1692632273000, timestamp_human='2023-08-21T15:37:53Z'), FactData(
id='04CA00D571634792', time_limit='Finite', timestamp=1692031015000, timestamp_human='2023-08-14T16:36:55Z')]                                                          
2023-08-14 16:38:05 INFO :: py_publish.py:409:batch_gc() :: Collecting IDs: [b'04CA000ACC65CA96', b'04CA007ACD75D2C7', b'04CA00D571634792']                            
2023-08-14 16:38:05 INFO :: py_publish.py:444:gc_txs() :: certificate file location: /home/orcfax/git/mlabs/coop.0/.coop-publisher-cli/certificate.pem                 
2023-08-14 16:38:05 INFO :: py_publish.py:120:tls_credentials() :: certificate file location: /home/orcfax/git/mlabs/coop.0/.coop-publisher-cli/certificate.pem        
2023-08-14 16:38:05 INFO :: py_publish.py:132:submitter() :: submitting Tx as: bedfff1b6762f7a95437ab8ca30b3244dfe44029125d23656062a8b6                                
2023-08-14 16:38:11 INFO :: py_publish.py:458:gc_txs() :: gc_fs_tx { 
}
info {
  tx_builder_info {
    obsolete_fs_ids: "04CA00D571634792"
    valid_fs_ids: "04CA000ACC65CA96"
    valid_fs_ids: "04CA007ACD75D2C7"
  }
}

2023-08-14 16:38:11 INFO :: py_publish.py:467:gc_txs() :: newly obsoleted statements: 1
2023-08-14 16:38:11 INFO :: py_publish.py:468:gc_txs() :: items not found: 0

Great find! I was doing deep testing today, and couldn't reproduce it directly at the Plutus level. I suspected something like this being an issue.

I appreciate you checking it out! :pray: thanks Drazen!

Can you document that also at

Totally. Looks like a good place for that too. Should be able to find some time before the end of the week!

[ross-spencer]

Forgot to close this out, if in error, please re-open and comment. Locally timestamps are showing correctly when milliseconds are used, and GC is ignoring those that have times that haven't elapsed.