Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

interop with CP3PRO #331

Open
scottlamb opened this issue Dec 11, 2024 · 2 comments
Open

interop with CP3PRO #331

scottlamb opened this issue Dec 11, 2024 · 2 comments

Comments

@scottlamb
Copy link
Owner

Moving from #33: @nalonsor1 wrote that a camera called CP3PRO (a Tenda CP3 Pro, I presume?) does not work, and pasted the following log:

Moonfire logs
2024-12-09T20:52:54.829156 INFO main moonfire_nvr::cmds: Opening /var/lib/moonfire-nvr/db/db in ReadWrite mode with SQLite version 3.40.1
2024-12-09T20:52:54.839281 INFO main moonfire_db::db: Loading video sample entries
2024-12-09T20:52:54.839521 INFO main moonfire_db::db: Loaded 1 video sample entries
2024-12-09T20:52:54.839684 INFO main moonfire_db::db: Loading sample file dirs
2024-12-09T20:52:54.839964 INFO main moonfire_db::db: Loaded 1 sample file dirs
2024-12-09T20:52:54.840100 INFO main moonfire_db::db: Loading cameras
2024-12-09T20:52:54.840312 INFO main moonfire_db::db: Loaded 2 cameras
2024-12-09T20:52:54.840453 INFO main moonfire_db::db: Loading streams
2024-12-09T20:52:54.840749 INFO main moonfire_db::db: Loaded 2 streams
2024-12-09T20:52:54.840908 INFO main moonfire_db::db: Loading recordings for camera CP3PRO stream Main
2024-12-09T20:52:54.841100 INFO main moonfire_db::db: Loaded 0 recordings for camera CP3PRO stream Main
2024-12-09T20:52:54.841233 INFO main moonfire_db::db: Loading recordings for camera test stream Main
2024-12-09T20:52:54.841459 INFO main moonfire_db::db: Loaded 1 recordings for camera test stream Main
2024-12-09T20:52:54.841606 INFO main moonfire_nvr::cmds::run: Database is loaded.
2024-12-09T20:52:54.842612 INFO main moonfire_nvr::cmds::run: Directories are opened.
2024-12-09T20:52:54.842766 INFO main moonfire_nvr::cmds::run: Resolved timezone: Europe/Madrid
2024-12-09T20:52:54.842913 INFO main moonfire_nvr::cmds::run: Starting syncer for path /media/nvr/sample
2024-12-09T20:52:54.843620 INFO main syncer{path=/media/nvr/sample}: moonfire_db::writer: initial rotation
2024-12-09T20:52:54.845240 INFO main syncer{path=/media/nvr/sample}:flush{flush_count=0 reason="synchronous deletion"}: moonfire_db::db: flush complete:
/media/nvr/sample: added 0B in 0 recordings (), deleted 607K 658B in 1 (2/107), GCed 0 recordings ().
2024-12-09T20:52:54.846864 INFO main syncer{path=/media/nvr/sample}:flush{flush_count=1 reason="synchronous garbage collection"}: moonfire_db::db: flush complete:
/media/nvr/sample: added 0B in 0 recordings (), deleted 0B in 0 (), GCed 3 recordings (2/106, 2/105, 2/107).
2024-12-09T20:52:54.847385 INFO main moonfire_nvr::cmds::run: no LISTEN_FDs
2024-12-09T20:52:54.851340 INFO s-test-main streamer{stream="test-main"}: moonfire_nvr::cmds::run: starting
2024-12-09T20:52:54.851556 INFO s-test-main streamer{stream="test-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.40.26:8554/profile1
2024-12-09T20:52:54.852087 INFO s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::cmds::run: starting
2024-12-09T20:52:54.852270 INFO s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.151.187/tenda
2024-12-09T20:52:54.852585 INFO sync-1 syncer{path=/media/nvr/sample}: moonfire_db::writer: starting
2024-12-09T20:52:54.859634 INFO main moonfire_nvr::cmds::run: Ready to serve HTTP requests
2024-12-09T20:52:54.969624 WARN tokio-runtime-worker streamer{stream="test-main"}: retina::codec::h264: Ignoring bad H.264 format-specific-params "profile-level-id=4DE028;packetization-mode=1;sprop-parameter-sets=AAAAAWdNABaNjUBQF/yzcBAQFAAALuAABX5AEA==,AAAAAWjuOIA=": only SPS and PPS expected in parameter sets
2024-12-09T20:52:55.089364 WARN tokio-runtime-worker streamer{stream="test-main"}: retina::client: Ignoring data on unassigned RTSP interleaved data channel 2. This is the first such message. Following messages will be logged at trace priority only.

conn: 192.168.40.124:46506(me)->192.168.40.26:8554@2024-12-09T20:52:54
msg: 21001@2024-12-09T20:52:55
data: Length: 332 (0x14c) bytes
0000: 80 88 00 00 f8 c3 82 98 f0 f0 bb 7c d5 d5 d5 d5 ...........|....
0010: d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 ................
0020: d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 ................
0030: d5 d5 55 55 55 55 d5 d5 d5 d5 55 55 d5 d5 d5 d5 ..UUUU....UU....
0040: d5 d5 d5 55 55 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 ...UU...........
0050: d5 d5 d5 d5 d5 55 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 .....U..........
0060: d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 55 55 55 d5 55 ...........UUU.U
0070: 55 55 55 55 d5 d5 d5 d5 d5 d5 d5 55 d5 55 d5 d5 UUUU.......U.U..
...204 (0xcc) bytes not shown...
2024-12-09T20:53:24.853386 WARN s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_base::clock: opening rtsp://192.168.151.187/tenda took PT30.000978861S!
2024-12-09T20:53:24.853572 WARN s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN
caused by: deadline has elapsed
2024-12-09T20:53:25.853791 INFO s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.151.187/tenda
2024-12-09T20:53:55.855099 WARN s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_base::clock: opening rtsp://192.168.151.187/tenda took PT30.001111804S!
2024-12-09T20:53:55.855256 WARN s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN
caused by: deadline has elapsed
2024-12-09T20:53:56.855483 INFO s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.151.187/tenda
^C2024-12-09T20:53:58.989830 INFO main moonfire_nvr::cmds::run: Received SIGINT; shutting down gracefully. Send another SIGINT or SIGTERM to shut down immediately.
2024-12-09T20:53:58.989893 INFO main moonfire_nvr::cmds::run: Shutting down streamers and syncers.
2024-12-09T20:53:59.023788 INFO s-test-main streamer{stream="test-main"}: moonfire_nvr::streamer: shutting down
^C2024-12-09T20:54:08.726849 ERROR main moonfire_nvr: exiting due to error err=CANCELLED: immediate shutdown due to second signal (SIGINT)
root@www:~#

The error is here:

2024-12-09T20:53:24.853572 WARN s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN
caused by: deadline has elapsed

I'll improve that message, but it means Moonfire didn't receive a full frame within 30 seconds. There might be clues as to why in a couple earlier messages:

2024-12-09T20:52:54.969624 WARN tokio-runtime-worker streamer{stream="test-main"}: retina::codec::h264: Ignoring bad H.264 format-specific-params "profile-level-id=4DE028;packetization-mode=1;sprop-parameter-sets=AAAAAWdNABaNjUBQF/yzcBAQFAAALuAABX5AEA==,AAAAAWjuOIA=": only SPS and PPS expected in parameter sets

That sprop-parameter-sets starts with (converted from base64 to hex) 00000001674d00168d8d405017fcb37010101400002ee000057e4010. The 00000001 is the problem; it's an Annex B NAL separator, which shouldn't be there. But it's probably harmless to add some code to look for that separator and skip over it, and it might help.

...but I'm more concerned about the following message:

2024-12-09T20:52:55.089364 WARN tokio-runtime-worker streamer{stream="test-main"}: retina::client: Ignoring data on unassigned RTSP interleaved data channel 2. This is the first such message. Following messages will be logged at trace priority only.

conn: 192.168.40.124:46506(me)->192.168.40.26:8554@2024-12-09T20:52:54
msg: 21001@2024-12-09T20:52:55
data: Length: 332 (0x14c) bytes
0000: 80 88 00 00 f8 c3 82 98 f0 f0 bb 7c d5 d5 d5 d5 ...........|....
0010: d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 ................
0020: d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 ................
0030: d5 d5 55 55 55 55 d5 d5 d5 d5 55 55 d5 d5 d5 d5 ..UUUU....UU....
0040: d5 d5 d5 55 55 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 ...UU...........
0050: d5 d5 d5 d5 d5 55 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 .....U..........
0060: d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 d5 55 55 55 d5 55 ...........UUU.U
0070: 55 55 55 55 d5 d5 d5 d5 d5 d5 d5 55 d5 55 d5 d5 UUUU.......U.U..
...204 (0xcc) bytes not shown...

If it's sending the data on a different channel than expected, that could certainly cause the problem. Not as sure how we'd work around this one.

@nalonsor1 Would you feel comfortable getting a packet capture of the traffic to 192.168.40.26:8554 via say Wireshark? You could share it with me over email if you don't want to paste it in the public channel. This might have data that would help understand more closely what's going on.

scottlamb added a commit that referenced this issue Dec 11, 2024
Before, it'd look like the following, as mentioned in
#331:

```
2024-12-09T20:53:24.853572 WARN s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN
caused by: deadline has elapsed
```

...which isn't as clear as it could be, particularly if you don't notice
the `caused by` bit. After, it should look more like the following:

```
2024-12-09T20:53:24.853572 WARN s-CP3PRO-main streamer{stream="CP3PRO-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=DEADLINE_EXCEEDED unable to play stream and get first frame within PT30S
caused by: deadline has elapsed
```
@nalonsor1
Copy link

Hello:
sorry about the confusion
The test config I used is based on two cams:
Tenda CP3 192.168.40.124 streaming in h.264
Tenda CP3PRO 192.168.151.187 streaming in h.265

and yes: the h.265 stream is from a Tenda CP3PRO

but forget all about 192.168.40.124 as its a TENDA CP3 configured for a test and streaming in h.264.

Tenda CP3 h.264 192.168.40.124 is working fine for months streaming in h.264 to Moonfire NVR standard without h.265 support

I will plug a new tenda CP3PRO and config moonfire-nvr h.265 version with it as the only stream in h.265 for a more clean log.

I will keep you informed when i finish doint it.

best regards and thank you again !!!

@nalonsor1
Copy link

Here you have: configured with only one cp3pro streaming at h.265

Tenda CP3PRO v22.5.4.79 192.138.40.30
rtsp://admin:admin123456@192.168.40.30/ch=1?subtype=1
H.265 hevc
640x368
FPS:20
Planar 4:2:0 YUV

2024-12-12T21:09:09.653169 INFO main moonfire_nvr::cmds: Opening /var/lib/moonfire-nvr/db/db in ReadWrite mode with SQLite version 3.40.1
2024-12-12T21:09:09.655508 INFO main moonfire_db::db: Loading video sample entries
2024-12-12T21:09:09.655731 INFO main moonfire_db::db: Loaded 1 video sample entries
2024-12-12T21:09:09.655898 INFO main moonfire_db::db: Loading sample file dirs
2024-12-12T21:09:09.656118 INFO main moonfire_db::db: Loaded 1 sample file dirs
2024-12-12T21:09:09.656268 INFO main moonfire_db::db: Loading cameras
2024-12-12T21:09:09.656452 INFO main moonfire_db::db: Loaded 1 cameras
2024-12-12T21:09:09.656586 INFO main moonfire_db::db: Loading streams
2024-12-12T21:09:09.656810 INFO main moonfire_db::db: Loaded 1 streams
2024-12-12T21:09:09.656946 INFO main moonfire_db::db: Loading recordings for camera CP3PRO2 stream Main
2024-12-12T21:09:09.657123 INFO main moonfire_db::db: Loaded 0 recordings for camera CP3PRO2 stream Main
2024-12-12T21:09:09.657267 INFO main moonfire_nvr::cmds::run: Database is loaded.
2024-12-12T21:09:09.658110 INFO main moonfire_nvr::cmds::run: Directories are opened.
2024-12-12T21:09:09.658260 INFO main moonfire_nvr::cmds::run: Resolved timezone: Europe/Madrid
2024-12-12T21:09:09.658384 INFO main moonfire_nvr::cmds::run: Starting syncer for path /media/nvr/sample
2024-12-12T21:09:09.658577 INFO main syncer{path=/media/nvr/sample}: moonfire_db::writer: initial rotation
2024-12-12T21:09:09.659179 INFO main syncer{path=/media/nvr/sample}:flush{flush_count=0 reason="synchronous deletion"}: moonfire_db::db: flush complete: no recording changes
2024-12-12T21:09:09.659492 INFO main moonfire_nvr::cmds::run: no LISTEN_FDs
2024-12-12T21:09:09.667305 INFO s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::cmds::run: starting
2024-12-12T21:09:09.667499 INFO s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.40.30/ch=1?subtype=1
2024-12-12T21:09:09.667881 INFO sync-1 syncer{path=/media/nvr/sample}: moonfire_db::writer: starting
2024-12-12T21:09:09.669261 INFO main moonfire_nvr::cmds::run: Ready to serve HTTP requests
2024-12-12T21:09:09.974402 WARN tokio-runtime-worker streamer{stream="CP3PRO2-main"}: retina::codec::h265: Ignoring bad H.265 format-specific-params "profile-space=0;profile-id=1;tier-flag=0;level-id=63;interop-constraints=900000000000;sprop-vps=QAEMAf//AWAAAAMAkAAAAwAAAwA/LAwAAgAAAwAoAAIAAgACgA==;sprop-sps=QgEBAWAAAAMAkAAAAwAAAwA/oAUCAXFlLkkyS7I=;sprop-pps=RAHA8vAzJA==": failed to parse SPS: ReaderErrorFor("num_positive_pics", Error { kind: UnexpectedEof, message: "failed to fill whole buffer" })
2024-12-12T21:09:10.452749 WARN s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN: unable to get first frame
caused by: FU has inconsistent NAL type: Header { unit_type: IdrWRadl, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 } then Header { unit_type: TrailR, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 }

conn: 192.168.40.124:32802(me)->192.168.40.30:554@2024-12-12T21:09:09
stream: TCP, interleaved channel ids 0-1
ssrc: 584908b2
seq: 4646
pkt: 2928@2024-12-12T21:09:10
2024-12-12T21:09:11.453072 INFO s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.40.30/ch=1?subtype=1
2024-12-12T21:09:11.528985 WARN tokio-runtime-worker streamer{stream="CP3PRO2-main"}: retina::codec::h265: Ignoring bad H.265 format-specific-params "profile-space=0;profile-id=1;tier-flag=0;level-id=63;interop-constraints=900000000000;sprop-vps=QAEMAf//AWAAAAMAkAAAAwAAAwA/LAwAAgAAAwAoAAIAAgACgA==;sprop-sps=QgEBAWAAAAMAkAAAAwAAAwA/oAUCAXFlLkkyS7I=;sprop-pps=RAHA8vAzJA==": failed to parse SPS: ReaderErrorFor("num_positive_pics", Error { kind: UnexpectedEof, message: "failed to fill whole buffer" })
2024-12-12T21:09:11.810225 WARN s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN: unable to get first frame
caused by: FU has inconsistent NAL type: Header { unit_type: IdrWRadl, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 } then Header { unit_type: TrailR, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 }

conn: 192.168.40.124:32814(me)->192.168.40.30:554@2024-12-12T21:09:11
stream: TCP, interleaved channel ids 0-1
ssrc: 0a7de584
seq: 49369
pkt: 2929@2024-12-12T21:09:11
2024-12-12T21:09:12.810501 INFO s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.40.30/ch=1?subtype=1
2024-12-12T21:09:12.810581 INFO s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: waiting up to 58.999612163s for TEARDOWN or expiration of 1 stale sessions
2024-12-12T21:09:14.828442 INFO s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: done waiting; no more stale sessions
2024-12-12T21:09:15.335638 WARN tokio-runtime-worker streamer{stream="CP3PRO2-main"}: retina::codec::h265: Ignoring bad H.265 format-specific-params "profile-space=0;profile-id=1;tier-flag=0;level-id=63;interop-constraints=900000000000;sprop-vps=QAEMAf//AWAAAAMAkAAAAwAAAwA/LAwAAgAAAwAoAAIAAgACgA==;sprop-sps=QgEBAWAAAAMAkAAAAwAAAwA/oAUCAXFlLkkyS7I=;sprop-pps=RAHA8vAzJA==": failed to parse SPS: ReaderErrorFor("num_positive_pics", Error { kind: UnexpectedEof, message: "failed to fill whole buffer" })
2024-12-12T21:09:15.470993 WARN s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN: unable to get first frame
caused by: FU has inconsistent NAL type: Header { unit_type: IdrWRadl, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 } then Header { unit_type: TrailR, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 }

conn: 192.168.40.124:32824(me)->192.168.40.30:554@2024-12-12T21:09:14
stream: TCP, interleaved channel ids 0-1
ssrc: e5a83bb8
seq: 61436
pkt: 2930@2024-12-12T21:09:15
2024-12-12T21:09:16.471254 INFO s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: opening input url=rtsp://192.168.40.30/ch=1?subtype=1
2024-12-12T21:09:16.683706 WARN tokio-runtime-worker streamer{stream="CP3PRO2-main"}: retina::codec::h265: Ignoring bad H.265 format-specific-params "profile-space=0;profile-id=1;tier-flag=0;level-id=63;interop-constraints=900000000000;sprop-vps=QAEMAf//AWAAAAMAkAAAAwAAAwA/LAwAAgAAAwAoAAIAAgACgA==;sprop-sps=QgEBAWAAAAMAkAAAAwAAAwA/oAUCAXFlLkkyS7I=;sprop-pps=RAHA8vAzJA==": failed to parse SPS: ReaderErrorFor("num_positive_pics", Error { kind: UnexpectedEof, message: "failed to fill whole buffer" })
2024-12-12T21:09:16.827141 WARN s-CP3PRO2-main streamer{stream="CP3PRO2-main"}: moonfire_nvr::streamer: sleeping for 1 s after error err=UNKNOWN: unable to get first frame
caused by: FU has inconsistent NAL type: Header { unit_type: IdrWRadl, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 } then Header { unit_type: TrailR, nuh_layer_id: 0, nuh_temporal_id_plus1: 1 }

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants