small problems noticed when running dynamic flow_test.

[petersilva]

This issue is going to be a grab bag of different things noticed trying to run dynamic_flow test:

1. message about renames (no actual problem, just messaging)

subscribe_u_sftp_f60_03.log:2024-02-05 13:16:56,914 [ERROR] sarracenia.flowcb.v2wrapper sumstrFromMessage unknown fileOp: {'rename': '/home/peter/sarra_devdocroot/downloaded_by_sub_amqp/20240205/WXO-DD/bulletins/alphanumeric/20240205/SX/KWAL/18/SXCN40_KWAL_051814___46154'}

[petersilva]

Another error message:

ubscribe_cdnld_f21_01.log:2024-02-17 22:18:48,645 [ERROR] sarracenia validate malformed pubTime: 031846.833
subscribe_cdnld_f21_01.log:2024-02-17 22:18:48,645 [ERROR] sarracenia.moth.amqp _msgRawToDict message acknowledged and discarded: {'_format': 'v03', '_deleteOnPost': {'exchange', 'ack_id', '_format',
 'source', 'local_offset', 'subtopic'}, 'pubTime': '031846.833', 'baseUrl': 'https://hpfx.collab.science.gc.ca', 'relPath': '/20240218/WXO-DD/.hello_weather/observations/09/09820.2.ALERT.PUB.EN.SPX~2
0240218030500-20240218050500-1183in', 'identity': {'method': 'arbitrary', 'value': 'd19f362f2b2aae3e6da38066b17b9646'}, 'source': 'tfeed', 'blocks': {'method': 'partitioned', 'size': '63584', 'count'
: '1', 'remainder': '0', 'number': '0'}, 'atime': '20240218T031839.0307264328', 'mtime': '20240218T031839.0347263813', 'mode': '666', 'sundew_extension': 'DMS:CMC:WXR-TRANSCODER-OBS-DATAMART-IVR:AUDI
O', 'to_clusters': 'DDI,DDSR', 'x-delay': '0', 'from_cluster': 'DDSR.CMC', 'exchange': 'xcsarra', 'subtopic': ['20240218', 'WXO-DD', 'hello_weather', 'observations', '09'], 'ack_id': 37, 'local_offse

ok.. so it looks like subscribe_cdnld is getting malformed messages... with a fractional pubtime... upstream of it, is:

cpump_xvan_f14_01.log:2024-02-17 22:18:48,460 [INFO] received: { "pubTime":"", "baseUrl":"https://hpfx.collab.science.gc.ca", "relPath":"/20240218/WXO-DD/.hello_weather/observations/09/09820.2.ALERT.PUB.EN.SPX~20240218030500-20240218050500-1183in", "topic":"v03.post.20240218.WXO-DD.hello_weather.observations.09", "identity":{  "method" : "arbitrary", "value" : "d19f362f2b2aae3e6da38066b17b9646"  } , "mtime":"20240218031839.0347263813", "atime":"20240218031839.0307264328", "mode":"0666", "size":"63584", "sundew_extension":"DMS:CMC:WXR-TRANSCODER-OBS-DATAMART-IVR:AUDIO", "to_clusters":"DDI,DDSR", "x-delay":"0", "from_cluster":"DDSR.CMC"}

cpump_xvan is publishing a recored with a blank pubTime... hmm... the source
received from cpump_pelle_dd* look like:

cpump_pelle_dd1_f04_01.log:2024-02-17 22:18:48,188 [INFO] received: { "pubTime":"20240218031846.833", "baseUrl":"https://hpfx.collab.science.gc.ca", "relPath":"/20240218/WXO-DD/.hello_weather/observations/09/09820.2.ALERT.PUB.EN.SPX~20240218030500-20240218050500-1183in", "topic":"v02.post.20240218.WXO-DD.hello_weather.observations.09", "identity":{  "method" : "arbitrary", "value" : "d19f362f2b2aae3e6da38066b17b9646"  } , "mtime":"20240218031839.0347263813", "atime":"20240218031839.0307264328", "mode":"0666", "size":"63584", "from_cluster":"DDSR.CMC", "x-delay":"0", "to_clusters":"DDI,DDSR", "sundew_extension":"DMS:CMC:WXR-TRANSCODER-OBS-DATAMART-IVR:AUDIO"}
cpump_pelle_dd1_f04_01.log:2024-02-17 22:18:48,188 [INFO] published: { "pubTime":"20240218031846.833", "baseUrl":"https://hpfx.collab.science.gc.ca", "relPath":"/20240218/WXO-DD/.hello_weather/observations/09/09820.2.ALERT.PUB.EN.SPX~20240218030500-20240218050500-1183in", "topic":"v03.post.20240218.WXO-DD.hello_weather.observations.09", "identity":{  "method" : "arbitrary", "value" : "d19f362f2b2aae3e6da38066b17b9646"  } , "mtime":"20240218031839.0347263813", "atime":"20240218031839.0307264328", "mode":"0666", "size":"63584", "from_cluster":"DDSR.CMC", "x-delay":"0", "to_clusters":"DDI,DDSR", "sundew_extension":"DMS:CMC:WXR-TRANSCODER-OBS-DATAMART-IVR:AUDIO"}

so the shovel is supposedly ok, but when the xvan receives it, the pubTime is missing.

[petersilva]

OK... so turning debug on, then found this:

2024-02-17 23:02:15,276 [DEBUG] successfully parsed message body: { "pubTime" : "20240218T040210.398046494", "baseUrl" : "https://hpfx.collab.science.gc.ca", "relPath" : "/20240218/WXO-DD/model_ohps/slfe/100m/00/005/20240218T00Z_MSC_OHPS-SLFE_RiverVelocityY_DBS-Avg_PS100m_PT005H.nc", "source" : "MSC-SCI-CMC-OPS", "size" : "116690126", "atime" : "20240218T040153.0711607933", "mtime" : "20240218T040153.211161852", "mode" : "644", "from_cluster" : "DDSR.CMC", "to_clusters" : "DDSR.SCIENCE,DDSR.CMC,DDI.CMC,DDI.SCIENCE,DDSR.STAGE" }
2024-02-17 23:02:15,276 [INFO] received: { "pubTime":"", "baseUrl":"https://hpfx.collab.science.gc.ca", "relPath":"/20240218/WXO-DD/model_ohps/slfe/100m/00/005/20240218T00Z_MSC_OHPS-SLFE_RiverVelocityY_DBS-Avg_PS100m_PT005H.nc", "topic":"v03.post.20240218.WXO-DD.model_ohps.slfe.100m.00.005", "identity":{  "method" : "md5", "value" : "mcomIbaMClukYsDy4QYsew=="  } , "mtime":"20240218040153.211161852", "atime":"20240218040153.0711607933", "mode":"0644", "size":"116690126", "to_clusters":"DDSR.SCIENCE,DDSR.CMC,DDI.CMC,DDI.SCIENCE,DDSR.STAGE", "from_cluster":"DDSR.CMC"}

so if the pubTime has a "T" in it, the C code fails to decode it properly.

opening: MetPX/sarrac#143