ZoneMinder Forums

Posted: **Wed Jan 24, 2024 2:30 am**

I am creating a new topic as it may not be related to memory leaks.

In the regular log:
1/23/24, 11:12:54 AM MST zmc_m2 283196 ERR Error writing packet: Invalid argument zm_videostore.cpp 1414

Same time in debug log for that pid:

01/23/24 11:12:54.093161 zmc_m2[283196].DB1-zm_event.cpp/694 [Adding packet 4467]
01/23/24 11:12:54.093176 zmc_m2[283196].DB2-zm_event.cpp/314 [have_video_keyframe 1 codec_type 0 == video? 1 packet keyframe 0]
01/23/24 11:12:54.093183 zmc_m2[283196].DB2-zm_event.cpp/316 [Adding to event: pts: 40460130, dts: 40460130, size: 32190, stream_index: 0, flags: 0000, keyframe(0) pos: -1, duration: 9000]
01/23/24 11:12:54.093195 zmc_m2[283196].DB1-zm_videostore.cpp/1029 [Queue size for 0 is 0]
01/23/24 11:12:54.093201 zmc_m2[283196].DB1-zm_videostore.cpp/1058 [Pushing on queue 0, size is 1]
01/23/24 11:12:54.093211 zmc_m2[283196].DB2-zm_videostore.cpp/1269 [Doing passthrough, just copy packet: pts: 40460130 * 1/90000=449.557000, dts: 40460130, size: 32190, stream_index: 0, video flags: 0000, keyframe(0) pos: -1, duration: 9000]
01/23/24 11:12:54.093241 zmc_m2[283196].WAR-zm_videostore.cpp/1387 [non increasing dts, fixing. our dts 31900500 stream 0 last_dts 31907700. reorder_queue_size=0]
01/23/24 11:12:54.093619 zmc_m2[283196].WAR-zm_videostore.cpp/1398 [pkt.dts(31907700) must be <= pkt.pts(31900500).Decompression must happen before presentation.]
01/23/24 11:12:54.093645 zmc_m2[283196].DB2-zm_videostore.cpp/1408 [finished pkt: pts: 31907700 * 1/90000=354.530000, dts: 31907700, size: 32190, stream_index: 0, video flags: 0000, keyframe(0) pos: -1, duration: 9000]
01/23/24 11:12:54.093655 zmc_m2[283196].DB3-zm_videostore.cpp/1409 [next_dts for stream 0 has become 31916700 last_dts 31907700]
01/23/24 11:12:54.093674 zmc_m2[283196].WAR-zm_ffmpeg.cpp/68 [Application provided invalid, non monotonically increasing dts to muxer in stream 0: 31907700 >= 31907700]
01/23/24 11:12:54.093746 zmc_m2[283196].ERR-zm_videostore.cpp/1414 [Error writing packet: Invalid argument]
01/23/24 11:12:54.093774 zmc_m2[283196].DB1-zm_event.cpp/402 [Have frame type Alarm from score(9) state 3 frames 3546 bulk frame interval 100 and mod46]
01/23/24 11:12:54.093784 zmc_m2[283196].DB1-zm_event.cpp/417 [frames 3546, score 9 max_score 9]
01/23/24 11:12:54.093791 zmc_m2[283196].DB1-zm_event.cpp/425 [Not Writing snapshot because frames 3546 score 9 > max 9]
01/23/24 11:12:54.093797 zmc_m2[283196].DB3-zm_event.cpp/439 [Not Writing alarm image because alarm frame already written]
01/23/24 11:12:54.093804 zmc_m2[283196].DB1-zm_event.cpp/473 [Frame delta is 1706033574.06 s - 1706033219.54 s = 354.51 s, score 9 zone_stats.size 0]
01/23/24 11:12:54.093813 zmc_m2[283196].DB1-zm_event.cpp/506 [Not Adding 49 frames to DB because write_to_db:0 or frames > analysis fps 10.000231 or BULK]
01/23/24 11:12:54.094434 zmc_m2[282808].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1706033574.093241, 'zmc_m2', 0, 283196, -1, 'WAR', 'non increasing dts, fixing. our dts 31900500 stream 0 last_dts 31907700. reorder_queue_size=0', 'zm_videostore.cpp', 1387 ), thread_id: 10324]
01/23/24 11:12:54.094891 zmc_m2[282808].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1706033574.093619, 'zmc_m2', 0, 283196, -1, 'WAR', 'pkt.dts(31907700) must be <= pkt.pts(31900500).Decompression must happen before presentation.', 'zm_videostore.cpp', 1398 ), thread_id: 10324]
01/23/24 11:12:54.095302 zmc_m2[282808].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1706033574.093674, 'zmc_m2', 0, 283196, -1, 'WAR', 'Application provided invalid, non monotonically increasing dts to muxer in stream 0: 31907700 >= 31907700', 'zm_ffmpeg.cpp', 68 ), thread_id: 10324]
01/23/24 11:12:54.095701 zmc_m2[282808].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1706033574.093746, 'zmc_m2', 0, 283196, -2, 'ERR', 'Error writing packet: Invalid argument', 'zm_videostore.cpp', 1414 ), thread_id: 10324]

I can provide more log info if needed but it is quite long.

Regards,

Mark

Posted: **Wed Jan 24, 2024 6:28 pm**

Code: Select all

Application provided invalid, non monotonically increasing dts to muxer in stream 0

I used to see this when transcoding some videos in FFMPEG. The dts (display time stamp) of two frames in succession are the same, which is viewed as some kind of heinous error ... surely FFMPEG should have a --suck-it-up option or --just-deal-with-it = yes ...

In the end I had to make a hacked FFMPEG build that just ignored it internally, no error, no exitting, just [bleeping] get on with it ...

It looks like maybe your video stream has some minor compliance issues regarding time running forwards, and the same sort of defensive checking is tripping up on it.

Posted: **Wed Jan 24, 2024 10:12 pm**

Normally we detecte out of order packets and default reorder_queue_size to 2*keyframe interval, which seems to be good enough for most cameras.

Those logs say reorder_queue_size=0, which means it is either very confused or there is some case that we aren't handling right.

You can manually override by setting reorder_queue_size= in Recording -> OPtions

Posted: **Thu Jan 25, 2024 6:25 pm**

iconnor wrote: ↑Wed Jan 24, 2024 10:12 pm Normally we detecte out of order packets and default reorder_queue_size to 2*keyframe interval, which seems to be good enough for most cameras.

Those logs say reorder_queue_size=0, which means it is either very confused or there is some case that we aren't handling right.

You can manually override by setting reorder_queue_size= in Recording -> OPtions

"Out of order packets" sounds like a network level problem.

The "non-monotonic DTS" thing is a broken video stream/file. While that could, I suppose, be caused by network packets still being out of order -- is it likely it is the video source (camera) that is broken? As I said, I've had this reading from files on a local disk, that were generated by a camera/source which wasn't 100% sane when it came to timestamping the frames. Some DTS values were duplicated on neighbouring frames.

FFMPEG spat its dummy when that happened, and wouldn't transcode the video.

Posted: **Thu Jan 25, 2024 7:16 pm**

I have a server doing these sporadically and I've realised the cause. If the event recording starts before we get an out of order packet, we won't know that we need the buffering. So I'm thinking I need to ALWAYS keep a reorder buffer going, which kinda sucks.

Maybe I can sort the packets as they come in instead of as they go out, but I think I tried that already and it didn't work...

Posted: **Sat Feb 10, 2024 8:46 am**

I think I have a similar (or same problem?)

Zoneminder version is v1.37.48

Log in Web gives:
10.02.24, 04:36:19 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:19 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:19 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:19 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:19 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:19 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:18 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:18 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:18 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:18 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:18 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:18 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427
10.02.24, 04:36:18 MEZ zmc_m8 4669 ERR Error writing packet: Invalid argument zm_videostore.cpp 1427

Debug-Log was activated and set to debug level 3 for zmc_m8:
02/10/24 04:36:19.217470 zmc_m8[1111].DB3-zm_monitor.cpp/1947 [Motion detection is enabled?(1) signal(1) signal_change(0) trigger state(Cancel) image index -1]
02/10/24 04:36:19.217474 zmc_m8[1111].DB3-zm_monitor.cpp/2404 [Not video, not clearing packets]
02/10/24 04:36:19.217478 zmc_m8[1111].DB2-zm_packetqueue.cpp/555 [Incrementing 0x562ce8521160, queue size 94, end? 0, deleting 0]
02/10/24 04:36:19.217483 zmc_m8[1111].DB2-zm_packetqueue.cpp/562 [Incrementing 0x562ce8521160, 0x562ce8521160 still not at end, so returning true]
02/10/24 04:36:19.217487 zmc_m8[1111].DB3-zm_packetqueue.cpp/480 [get_packet using it 0x562ce8521160 locking index 160661]
02/10/24 04:36:19.217492 zmc_m8[1111].DB2-zm_packetqueue.cpp/485 [Locked packet 160661, unlocking packetqueue mutex]
02/10/24 04:36:19.217496 zmc_m8[1111].DB3-zm_monitor.cpp/1947 [Motion detection is enabled?(1) signal(1) signal_change(0) trigger state(Cancel) image index 160661]
02/10/24 04:36:19.217501 zmc_m8[1111].DB1-zm_monitorlink_expression.cpp/68 [visit: Node: 0x562ce851b340 Token: 1 value 7]
02/10/24 04:36:19.217505 zmc_m8[1111].DB1-zm_monitorlink_expression.cpp/74 [Have monitorlink, return true, value]
02/10/24 04:36:19.217509 zmc_m8[1111].DB1-zm_monitor_monitorlink.cpp/223 [Checking all zones score is 14]
02/10/24 04:36:19.217513 zmc_m8[1111].DB1-zm_monitorlink_token.h/215 [Score from monitor cam4 Fluent is 14]
02/10/24 04:36:19.217518 zmc_m8[1111].DB1-zm_monitor.cpp/2059 [evaluate 1]
02/10/24 04:36:19.217522 zmc_m8[1111].DB1-zm_monitor.cpp/2179 [Not analysing 1]
02/10/24 04:36:19.217526 zmc_m8[1111].DB1-zm_monitor.cpp/2232 [Staying in PREALARM]
02/10/24 04:36:19.217530 zmc_m8[1111].DB3-zm_packetqueue.cpp/241 [stream index 0 ?= video_stream_id 0, keyframe 0, keep_keyframes 1, counts 58 > pre_event_count 25 at begin 1]
02/10/24 04:36:19.217535 zmc_m8[1111].DB2-zm_packetqueue.cpp/555 [Incrementing 0x562ce8521160, queue size 94, end? 0, deleting 0]
02/10/24 04:36:19.217539 zmc_m8[1111].DB2-zm_packetqueue.cpp/565 [At end]
02/10/24 04:36:19.217544 zmc_m8[1111].DB2-zm_packetqueue.cpp/470 [waiting. Queue size 94 it == end? 1]
02/10/24 04:36:19.217554 zmc_m8[4669].DB1-zm_event.cpp/694 [Adding packet 160658]
02/10/24 04:36:19.217559 zmc_m8[4669].DB2-zm_event.cpp/314 [have_video_keyframe 1 codec_type 0 == video? 1 packet keyframe 0]
02/10/24 04:36:19.217564 zmc_m8[4669].DB2-zm_event.cpp/316 [Adding to event: pts: 2682575900, dts: 2682575900, size: 22762, stream_index: 0, flags: 0000, keyframe(0) pos: 5168564977, duration: 83]
02/10/24 04:36:19.217573 zmc_m8[4669].DB1-zm_videostore.cpp/1042 [Queue size for 0 is 102]
02/10/24 04:36:19.217578 zmc_m8[4669].DB1-zm_videostore.cpp/1052 [Found in order packet]
02/10/24 04:36:19.217582 zmc_m8[4669].DB1-zm_videostore.cpp/1071 [Pushing on queue 0, size is 103]
02/10/24 04:36:19.217587 zmc_m8[4669].DB2-zm_videostore.cpp/1282 [Doing passthrough, just copy packet: pts: 2682572305 * 1/1000=2682572.305000, dts: 2682572305, size: 26434, stream_index: 0, video flags: 0000, keyframe(0) pos: 5164540226, duration: 83]
02/10/24 04:36:19.217597 zmc_m8[4669].DB2-zm_videostore.cpp/1421 [finished pkt: pts: 212688 * 1/16000=13.293000, dts: 212688, size: 26434, stream_index: 0, video flags: 0000, keyframe(0) pos: -1, duration: 1328]
02/10/24 04:36:19.217603 zmc_m8[4669].DB3-zm_videostore.cpp/1422 [next_dts for stream 0 has become 214016 last_dts 212688]
02/10/24 04:36:19.217611 zmc_m8[4669].DB1-zm_event.cpp/402 [Have frame type Alarm from score(20) state 2 frames 309 bulk frame interval 100 and mod9]
02/10/24 04:36:19.217616 zmc_m8[4669].DB1-zm_event.cpp/456 [No image]
02/10/24 04:36:19.217621 zmc_m8[4669].DB1-zm_event.cpp/473 [Frame delta is 1707536179.18 s - 1707536162.19 s = 17.00 s, score 20 zone_stats.size 0]
02/10/24 04:36:19.217628 zmc_m8[4669].DB1-zm_event.cpp/506 [Not Adding 8 frames to DB because write_to_db:0 or frames > analysis fps 19.773329 or BULK]
02/10/24 04:36:19.217633 zmc_m8[4669].DB1-zm_event.cpp/694 [Adding packet 160659]
02/10/24 04:36:19.217638 zmc_m8[4669].DB2-zm_event.cpp/314 [have_video_keyframe 1 codec_type 0 == video? 1 packet keyframe 0]
02/10/24 04:36:19.217642 zmc_m8[4669].DB2-zm_event.cpp/316 [Adding to event: pts: 2682575967, dts: 2682575967, size: 24397, stream_index: 0, flags: 0000, keyframe(0) pos: 5168587759, duration: 83]
02/10/24 04:36:19.217647 zmc_m8[4669].DB1-zm_videostore.cpp/1042 [Queue size for 0 is 102]
02/10/24 04:36:19.217652 zmc_m8[4669].DB1-zm_videostore.cpp/1052 [Found in order packet]
02/10/24 04:36:19.217656 zmc_m8[4669].DB1-zm_videostore.cpp/1071 [Pushing on queue 0, size is 103]
02/10/24 04:36:19.217661 zmc_m8[4669].DB2-zm_videostore.cpp/1282 [Doing passthrough, just copy packet: pts: 2682572305 * 1/1000=2682572.305000, dts: 2682572305, size: 27432, stream_index: 0, video flags: 0000, keyframe(0) pos: 5165442651, duration: 83]
02/10/24 04:36:19.217667 zmc_m8[4669].DB2-zm_videostore.cpp/1421 [finished pkt: pts: 212688 * 1/16000=13.293000, dts: 212688, size: 27432, stream_index: 0, video flags: 0000, keyframe(0) pos: -1, duration: 1328]
02/10/24 04:36:19.217673 zmc_m8[4669].DB3-zm_videostore.cpp/1422 [next_dts for stream 0 has become 214016 last_dts 212688]
02/10/24 04:36:19.217679 zmc_m8[4669].WAR-zm_ffmpeg.cpp/68 [Application provided invalid, non monotonically increasing dts to muxer in stream 0: 212688 >= 212688]
02/10/24 04:36:19.217687 zmc_m8[4669].ERR-zm_videostore.cpp/1427 [Error writing packet: Invalid argument]
02/10/24 04:36:19.217724 zmc_m8[4669].DB1-zm_event.cpp/402 [Have frame type Alarm from score(20) state 2 frames 310 bulk frame interval 100 and mod10]
02/10/24 04:36:19.217731 zmc_m8[4669].DB1-zm_event.cpp/456 [No image]
02/10/24 04:36:19.217736 zmc_m8[4669].DB1-zm_event.cpp/473 [Frame delta is 1707536179.19 s - 1707536162.19 s = 17.01 s, score 20 zone_stats.size 0]
02/10/24 04:36:19.217743 zmc_m8[4669].DB1-zm_event.cpp/506 [Not Adding 9 frames to DB because write_to_db:0 or frames > analysis fps 19.773329 or BULK]
02/10/24 04:36:19.217748 zmc_m8[4669].DB1-zm_event.cpp/694 [Adding packet -1]
02/10/24 04:36:19.217752 zmc_m8[4669].DB2-zm_event.cpp/314 [have_video_keyframe 1 codec_type 1 == video? 0 packet keyframe 1]
02/10/24 04:36:19.217757 zmc_m8[4669].DB2-zm_event.cpp/316 [Adding to event: pts: 2682575979, dts: 2682575979, size: 512, stream_index: 1, flags: 0001, keyframe(1) pos: 5168612176, duration: 64]
02/10/24 04:36:19.217762 zmc_m8[4669].DB1-zm_videostore.cpp/1042 [Queue size for 1 is 102]
02/10/24 04:36:19.217767 zmc_m8[4669].DB1-zm_videostore.cpp/1052 [Found in order packet]
02/10/24 04:36:19.217775 zmc_m8[4669].DB1-zm_videostore.cpp/1071 [Pushing on queue 1, size is 103]
02/10/24 04:36:19.217780 zmc_m8[4669].DB2-zm_videostore.cpp/1311 [input packet: pts: 2682568363 * 1/1000=2682568.363000, dts: 2682568363, size: 512, stream_index: 1, audio flags: 0001, keyframe(1) pos: 5163045772, duration: 64]
02/10/24 04:36:19.217787 zmc_m8[4669].DB2-zm_videostore.cpp/1377 [after pts adjustment: pts: 2682568363 * 1/1000=2682568.363000, dts: 2682568363, size: 512, stream_index: 1, audio flags: 0001, keyframe(1) pos: 5163045772, duration: 64]
02/10/24 04:36:19.217793 zmc_m8[4669].DB2-zm_videostore.cpp/1379 [after stream pts adjustment: pts: 149504 * 1/16000=9.344000, dts: 149504, size: 512, stream_index: 0, audio flags: 0001, keyframe(1) pos: -1, duration: 1024]
02/10/24 04:36:19.217799 zmc_m8[4669].DB2-zm_videostore.cpp/1421 [finished pkt: pts: 149504 * 1/16000=9.344000, dts: 149504, size: 512, stream_index: 1, audio flags: 0001, keyframe(1) pos: -1, duration: 1024]
02/10/24 04:36:19.217805 zmc_m8[4669].DB3-zm_videostore.cpp/1422 [next_dts for stream 1 has become 150528 last_dts 149504]
02/10/24 04:36:19.217827 zmc_m8[4669].DB1-zm_event.cpp/694 [Adding packet 160660]
02/10/24 04:36:19.217832 zmc_m8[4669].DB2-zm_event.cpp/314 [have_video_keyframe 1 codec_type 0 == video? 1 packet keyframe 0]
02/10/24 04:36:19.217837 zmc_m8[4669].DB2-zm_event.cpp/316 [Adding to event: pts: 2682576000, dts: 2682576000, size: 20226, stream_index: 0, flags: 0000, keyframe(0) pos: 5168612705, duration: 83]
02/10/24 04:36:19.217842 zmc_m8[4669].DB1-zm_videostore.cpp/1042 [Queue size for 0 is 102]
02/10/24 04:36:19.217846 zmc_m8[4669].DB1-zm_videostore.cpp/1052 [Found in order packet]
02/10/24 04:36:19.217851 zmc_m8[4669].DB1-zm_videostore.cpp/1071 [Pushing on queue 0, size is 103]
02/10/24 04:36:19.217855 zmc_m8[4669].DB2-zm_videostore.cpp/1282 [Doing passthrough, just copy packet: pts: 2682572338 * 1/1000=2682572.338000, dts: 2682572338, size: 26381, stream_index: 0, video flags: 0000, keyframe(0) pos: 5164566680, duration: 83]
02/10/24 04:36:19.217862 zmc_m8[4669].DB2-zm_videostore.cpp/1421 [finished pkt: pts: 213216 * 1/16000=13.326000, dts: 213216, size: 26381, stream_index: 0, video flags: 0000, keyframe(0) pos: -1, duration: 1328]
02/10/24 04:36:19.217868 zmc_m8[4669].DB3-zm_videostore.cpp/1422 [next_dts for stream 0 has become 214544 last_dts 213216]
02/10/24 04:36:19.217873 zmc_m8[4669].DB1-zm_event.cpp/402 [Have frame type Alarm from score(20) state 2 frames 311 bulk frame interval 100 and mod11]
02/10/24 04:36:19.217878 zmc_m8[4669].DB1-zm_event.cpp/456 [No image]
02/10/24 04:36:19.217882 zmc_m8[4669].DB1-zm_event.cpp/473 [Frame delta is 1707536179.21 s - 1707536162.19 s = 17.02 s, score 20 zone_stats.size 0]
02/10/24 04:36:19.217889 zmc_m8[4669].DB1-zm_event.cpp/506 [Not Adding 10 frames to DB because write_to_db:0 or frames > analysis fps 19.773329 or BULK]
02/10/24 04:36:19.217894 zmc_m8[4669].DB1-zm_event.cpp/694 [Adding packet -1]
02/10/24 04:36:19.217899 zmc_m8[4669].DB2-zm_event.cpp/314 [have_video_keyframe 1 codec_type 1 == video? 0 packet keyframe 1]
02/10/24 04:36:19.217903 zmc_m8[4669].DB2-zm_event.cpp/316 [Adding to event: pts: 2682576043, dts: 2682576043, size: 512, stream_index: 1, flags: 0001, keyframe(1) pos: 5168632951, duration: 64]
02/10/24 04:36:19.217909 zmc_m8[4669].DB1-zm_videostore.cpp/1042 [Queue size for 1 is 102]
02/10/24 04:36:19.217913 zmc_m8[4669].DB1-zm_videostore.cpp/1052 [Found in order packet]
02/10/24 04:36:19.217917 zmc_m8[4669].DB1-zm_videostore.cpp/1071 [Pushing on queue 1, size is 103]
02/10/24 04:36:19.217922 zmc_m8[4669].DB2-zm_videostore.cpp/1311 [input packet: pts: 2682568427 * 1/1000=2682568.427000, dts: 2682568427, size: 512, stream_index: 1, audio flags: 0001, keyframe(1) pos: 5163072646, duration: 64]
02/10/24 04:36:19.217928 zmc_m8[4669].DB2-zm_videostore.cpp/1377 [after pts adjustment: pts: 2682568427 * 1/1000=2682568.427000, dts: 2682568427, size: 512, stream_index: 1, audio flags: 0001, keyframe(1) pos: 5163072646, duration: 64]
02/10/24 04:36:19.217944 zmc_m8[4669].DB2-zm_videostore.cpp/1379 [after stream pts adjustment: pts: 150528 * 1/16000=9.408000, dts: 150528, size: 512, stream_index: 0, audio flags: 0001, keyframe(1) pos: -1, duration: 1024]
02/10/24 04:36:19.217950 zmc_m8[4669].DB2-zm_videostore.cpp/1421 [finished pkt: pts: 150528 * 1/16000=9.408000, dts: 150528, size: 512, stream_index: 1, audio flags: 0001, keyframe(1) pos: -1, duration: 1024]
02/10/24 04:36:19.217956 zmc_m8[4669].DB3-zm_videostore.cpp/1422 [next_dts for stream 1 has become 151552 last_dts 150528]
02/10/24 04:36:19.217975 zmc_m8[4669].DB1-zm_event.cpp/694 [Adding packet 160661]
02/10/24 04:36:19.217981 zmc_m8[4669].DB2-zm_event.cpp/314 [have_video_keyframe 1 codec_type 0 == video? 1 packet keyframe 0]
02/10/24 04:36:19.217985 zmc_m8[4669].DB2-zm_event.cpp/316 [Adding to event: pts: 2682576033, dts: 2682576033, size: 18989, stream_index: 0, flags: 0000, keyframe(0) pos: 5168633480, duration: 83]
02/10/24 04:36:19.217990 zmc_m8[4669].DB1-zm_videostore.cpp/1042 [Queue size for 0 is 102]
02/10/24 04:36:19.217994 zmc_m8[4669].DB1-zm_videostore.cpp/1052 [Found in order packet]
02/10/24 04:36:19.217999 zmc_m8[4669].DB1-zm_videostore.cpp/1071 [Pushing on queue 0, size is 103]
02/10/24 04:36:19.218003 zmc_m8[4669].DB2-zm_videostore.cpp/1282 [Doing passthrough, just copy packet: pts: 2682572371 * 1/1000=2682572.371000, dts: 2682572371, size: 28167, stream_index: 0, video flags: 0000, keyframe(0) pos: 5165470103, duration: 83]
02/10/24 04:36:19.218010 zmc_m8[4669].DB2-zm_videostore.cpp/1421 [finished pkt: pts: 213744 * 1/16000=13.359000, dts: 213744, size: 28167, stream_index: 0, video flags: 0000, keyframe(0) pos: -1, duration: 1328]
02/10/24 04:36:19.218016 zmc_m8[4669].DB3-zm_videostore.cpp/1422 [next_dts for stream 0 has become 215072 last_dts 213744]
02/10/24 04:36:19.218021 zmc_m8[4669].DB1-zm_event.cpp/402 [Have frame type Alarm from score(20) state 2 frames 312 bulk frame interval 100 and mod12]
02/10/24 04:36:19.218026 zmc_m8[4669].DB1-zm_event.cpp/456 [No image]
02/10/24 04:36:19.218030 zmc_m8[4669].DB1-zm_event.cpp/473 [Frame delta is 1707536179.21 s - 1707536162.19 s = 17.02 s, score 20 zone_stats.size 0]
02/10/24 04:36:19.218036 zmc_m8[4669].DB1-zm_event.cpp/506 [Not Adding 11 frames to DB because write_to_db:0 or frames > analysis fps 19.773329 or BULK]
02/10/24 04:36:19.218151 zmc_m8[1030].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1707536179.217687, 'zmc_m8', 0, 4669, -2, 'ERR', 'Error writing packet: Invalid argument', 'zm_videostore.cpp', 1427 ), thread_id: 67]
02/10/24 04:36:19.223988 zmc_m8[1026].DB2-zm_ffmpeg_camera.cpp/243 [ffmpeg_camera in: pts: 2682576066 * 1/1000=2682576.066000, dts: 2682576066, size: 20380, stream_index: 0, video flags: 0000, keyframe(0) pos: 5168652489, duration: 83]
02/10/24 04:36:19.224008 zmc_m8[1026].DB2-zm_monitor.cpp/2637 [Have packet stream_index:0 ?= videostream_id: 0 q.vpktcount 58 event? 1 image_count 160662]
02/10/24 04:36:19.224014 zmc_m8[1026].DB2-zm_packetqueue.cpp/137 [packet counts for 0 is 59]
02/10/24 04:36:19.224039 zmc_m8[1111].DB3-zm_packetqueue.cpp/480 [get_packet using it 0x562ce8521160 locking index 160662]
02/10/24 04:36:19.224054 zmc_m8[1111].DB2-zm_packetqueue.cpp/485 [Locked packet 160662, unlocking packetqueue mutex]
02/10/24 04:36:19.224061 zmc_m8[1111].DB3-zm_monitor.cpp/1947 [Motion detection is enabled?(1) signal(1) signal_change(0) trigger state(Cancel) image index 160662]
02/10/24 04:36:19.224067 zmc_m8[1111].DB1-zm_monitorlink_expression.cpp/68 [visit: Node: 0x562ce851b340 Token: 1 value 7]
02/10/24 04:36:19.224072 zmc_m8[1111].DB1-zm_monitorlink_expression.cpp/74 [Have monitorlink, return true, value]
02/10/24 04:36:19.224077 zmc_m8[1111].DB1-zm_monitor_monitorlink.cpp/223 [Checking all zones score is 14]
02/10/24 04:36:19.224081 zmc_m8[1111].DB1-zm_monitorlink_token.h/215 [Score from monitor cam4 Fluent is 14]

This is just a snap from the debug log. If you need more I can post it here..

Any suggestions?

Regards,
witom

Posted: **Thu May 02, 2024 7:35 pm**

ZM v1.37.58
Sometimes errors appear:

Code: Select all

5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	ERR	Error writing packet: Invalid argument	zm_videostore.cpp	1415
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	WAR	pkt.dts(2270423) must be <= pkt.pts(2270156).Decompression must happen before presentation.	zm_videostore.cpp	1399
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	WAR	non increasing dts, fixing. our dts 2270156 stream 0 last_dts 2270423. reorder_queue_size=20	zm_videostore.cpp	1388
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	ERR	Error writing packet: Invalid argument	zm_videostore.cpp	1415
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	WAR	pkt.dts(2270423) must be <= pkt.pts(2266556).Decompression must happen before presentation.	zm_videostore.cpp	1399
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	WAR	non increasing dts, fixing. our dts 2266556 stream 0 last_dts 2270423. reorder_queue_size=20	zm_videostore.cpp	1388
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	ERR	Error writing packet: Invalid argument	zm_videostore.cpp	1415
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	WAR	pkt.dts(2270423) must be <= pkt.pts(2262956).Decompression must happen before presentation.	zm_videostore.cpp	1399
5/2/24, 9:17:46 PM GMT+3	zmc_m5		716761	WAR	non increasing dts, fixing. our dts 2262956 stream 0 last_dts 2270423. reorder_queue_size=20	zm_videostore.cpp	1388
5/2/24, 9:17:45 PM GMT+3	zmc_m5		716761	ERR	Error writing packet: Invalid argument	zm_videostore.cpp	1415
5/2/24, 9:17:45 PM GMT+3	zmc_m5		716761	WAR	pkt.dts(2270423) must be <= pkt.pts(2259356).Decompression must happen before presentation.	zm_videostore.cpp	1399
5/2/24, 9:17:45 PM GMT+3	zmc_m5		716761	WAR	non increasing dts, fixing. our dts 2259356 stream 0 last_dts 2270423. reorder_queue_size=20	zm_videostore.cpp	1388
5/2/24, 9:17:45 PM GMT+3	zmc_m5		716761	ERR	Error writing packet: Invalid argument	zm_videostore.cpp	1415
5/2/24, 9:17:45 PM GMT+3	zmc_m5		716761	WAR	pkt.dts(2270423) must be <= pkt.pts(2255756).Decompression must happen before presentation.	zm_videostore.cpp	1399
5/2/24, 9:17:45 PM GMT+3	zmc_m5		716761	WAR	non increasing dts, fixing. our dts 2255756 stream 0 last_dts 2270423. reorder_queue_size=20	zm_videostore.cpp	1388

Posted: **Fri May 03, 2024 2:09 pm**

I see this all the time with cameras with a bad clock. When ntp syncs the clock jumps back in time.

Posted: **Fri May 03, 2024 2:38 pm**

Synchronization was once a day, changed it to once every hour.
I'll keep an eye on it.

Posted: **Fri May 03, 2024 5:13 pm**

iconnor wrote: ↑Fri May 03, 2024 2:09 pm I see this all the time with cameras with a bad clock. When ntp syncs the clock jumps back in time.

"pkt.dts(2270423)" on *every* packet. "Non increasing dts" -- that's very accurate statement.

It doesn't seem to have jumped back, it looks like the clock (well, the thing driving the display time stamp) is stopped. All frames to be displayed at the same time -- that's not video, that's a mess

Posted: **Fri May 03, 2024 8:45 pm**

That's a very good point. pts is changing, dts is not.

ZoneMinder Forums

Error writing packet: Invalid argument

Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument

Re: Error writing packet: Invalid argument