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.

Sign up for GitHub

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

Jump to bottom

I upgraded to 6.1 and had no sound on modem #81

Closed
InfiniteOtter opened this issue Apr 5, 2022 · 38 comments
Closed

I upgraded to 6.1 and had no sound on modem #81

InfiniteOtter opened this issue Apr 5, 2022 · 38 comments

Comments

@InfiniteOtter
Copy link

InfiniteOtter commented Apr 5, 2022 •
edited
Loading

6.1 gives me no sound. I went back to 5.9 and I am able to hear the modem and on a test call get the "Hello I am your modem, have a wonderful day." Message.
Sadly on a call, the person I call gets popping static. I can here them fine.

Pinephone Pro Explorer edition. Phosh Manjaro updated unstable version, boot sector erased.
@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 5, 2022

The "big" change in 0.6.1 was the move from Quectel's patched audio driver to Qualcomm's "stock" one, precisely to get rid of the static background noise.

Can you get modem's kernel log and openqti.log?

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Apr 5, 2022 •
edited
Loading

I am trying to figure out how the get the kernel log and openqti.log. I am not easily finding the file with the openqti.log fine with the find command so I searched the documentation and came up with this process:
sudo su
echo -ne "AT+SIMUSMS" /dev/ttyUSB2

I did not get a chat "Hello world" after entering this.

I texted to 1 555 0199 999 "help"
no response came back.
When I call the number, 1 555 0199 999. I get the message, "Hello I am your modem. Have a wonderful day."

My apologies for being clueless here. I would be happy to apply the 6.1 again for testing, but i would need to know how to provide results that will help.

@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 6, 2022 •
edited
Loading

The number you should be messaging is +01 555 019 999 9, if it doesn't have that 0 before the prefix the modem will let it pass and try to deliver it (it's an invalid number so it should get rejected by the network)
Let's try something else, if you run, as root:
echo -ne "AT+ADBON" /dev/ttyUSB2
The modem should disappear for a few seconds and appear again. This should enable ADB, which would let you pull the logs from the modem with adb pull /var/log/openqti.log and adb shell dmesg > modem_kernel_log.log
Does that work?
Be careful with that log, if you had some call running the numbers will appear there, so make sure you check the file before uploading it anywhere

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Apr 6, 2022 via email

@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 6, 2022

Sorry, I had a typo, it should be
echo -ne "AT+ADBON\r" /dev/ttyUSB2

It was missing the \r in both commands

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Apr 6, 2022 via email

@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 6, 2022

You still need to be running those commands as root!

Same as with echo -ne "AT+SIMUSMS\r" > /dev/ttyUSB2, first get a root terminal, then try both commands

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Apr 6, 2022 via email

@CodePhase
Copy link
Contributor

I have this problem also. I upgraded to 0.6.1 and since then I have noticed that the speaker and microphone don't seem to work after waking from suspend. If I power down my Pinephone Pro, wait about 30 seconds, then power it on the problem is gone. However, if I restart the phone the problem remains. Obviously if I try to answer an incoming call when suspend was active it will fail to have the speaker and microphone working there too.

I have attached logs of both working and not working. When it works, here is the process I use:

  • Power down (not restart) the phone and wait 30 seconds
  • Power on the phone
  • After the modem is brought up (indicated by the mobile strength symbol), restart the ModemManager service
  • After the modem is brought up again (indicated by the mobile strength symbol), restart NetworkManager and systemd-networkd
  • Restart chatty

If I don't follow this process my SMS doesn't work due to some silliness with Verizon (USA) LTE service and DNS. After that I use the loopback call feature in 0.6.1 to test the calling. Prior to that I would test it by calling the US Naval Observatory Master Clock system, which you might see in my logs
bootworks_dmesg-modem.txt
bootworks_dmesg-pinephone.txt
bootworks_eg25-manager.log
bootworks_modemmanager.log
bootworks_networkmanager.log
bootworks_openqti.log
suspfail_dmesg-modem.txt
suspfail_dmesg-pinephone.txt
suspfail_eg25-manager.log
suspfail_modemmanager.log
suspfail_networkmanager.log
suspfail_openqti.log

@CodePhase
Copy link
Contributor

Instead of powering off and powering on the phone to get the speaker / mic working, I forced the modem to reboot:

sudo su -
echo -ne "AT+QFASTBOOT\r" > /dev/ttyUSB2
fastboot reboot

After the modem came back on and registered with the network I was able to use the loopback calling feature to hear the test message from the modem.

@CodePhase
Copy link
Contributor

CodePhase commented Apr 7, 2022 •
edited
Loading

Interestingly, after restarting the modem from the last comment, I was not able to dial or receive calls. I had to also restart the ModemManager service:

sudo systemctl restart ModemManager

These logs were captured after calling the Pinephone (failed), then rebooting the modem, then restarting ModemManager, then calling the Pinephone again (worked) and finally calling from the Pinephone (worked)

dmesg-modem.txt
eg25-manager.log
modemmanager.log
openqti.log

@InfiniteOtter
Copy link
Author

CodePhase, this might help with some of it, it's in some of the documentation if you drill down.

Stop the modem from disappearing on suspend

Edit /usr/lib/udev/rules.d/80-modem-eg25.rules
Look at the last line: ACTION=="add", SUBSYSTEM=="usb", DRIVERS=="usb", ENV{DEVTYPE}=="usb_device", ATTRS{idVendor}=="2c7c", ATTRS{idProduct}=="0125", ATTR{power/persist}="0"
And change persist to 1: ACTION=="add", SUBSYSTEM=="usb", DRIVERS=="usb", ENV{DEVTYPE}=="usb_device", ATTRS{idVendor}=="2c7c", ATTRS{idProduct}=="0125", ATTR{power/persist}="1"

Edit /usr/share/eg25-manager/pine64,pinephone-pro.toml and make sure monitor_udev is set to false

I downloaded 6.1 again and installed it. The person on the other end still gets static and can barely make out what I say on the PInePhone Pro. On the positive side, I can hear them well and their voice actually sounds like their voice now.

@CodePhase
Copy link
Contributor

hello and thank you for your suggestion @InfiniteOtter but I already have those changes in place so hopefully there's something else to try.

@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 8, 2022

Okay there's two things here then:
@InfiniteOtter is it static, or is it feedback, or the gain might be so high they only hear noise? In my usual testing with default microphone values in the PinePhone Pro, I can put the Pro behind my laptop's screen at half a meter distance and I can hear myself through the other phone as if I had the speaker active (it is that high by default). Have you tried moving the microphone level slider to almost the lowest possible value in Settings -> Sound?

@CodePhase Taking a look at your modem's kernel log, it seems like the audio driver reset some parameter and set itself to 8K sampling rate, maybe I have to set it to 16K on every call now? Need to check it a bit (tested after suspend but not after having it for an hour suspended, maybe some part of the driver does something I haven't seen... not sure, but it would make sense for it to fail if it changes I2S to slave and changes the sampling rate by itself :( )

@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 8, 2022

@CodePhase Can you check if audio loss still persists with this build?

https://github.com/Biktorgj/pinephone_modem_sdk/releases/tag/0.6.2

@CodePhase
Copy link
Contributor

@Biktorgj I have installed the 0.6.2 build and done a small amount of testing. All the tests were successful! Here's what I did:

  • Installed 0.6.2 with the flashall script
  • Powered off (not reboot) and powered on
  • Called from Pinephone to US Naval Observatory Master Clock (success)
  • Called modem loopback number (success)
  • Called my landline from Pinephone (success)
  • Called Pinephone from landline (success)
  • Tried to send SMS (failed, but this is normal after a fresh boot)
  • Restarted ModemManager, then systemd-networkd + NetworkManager
  • Sent SMS (success)
  • Allowed Pinephone to suspend for 75 minutes
  • Called Pinephone (while in suspend) from landline (success)
  • Called landline from Pinephone (success)

If you're interested in the logs let me know and I'll post them in a comment. Great work @Biktorgj and thank you for coming up with this so fast! I know there is a note that 0.6.2 is experimental so I'll keep running it and let you know if anything else crops up.

@CodePhase
Copy link
Contributor

well, bad news; I have new problems while running the 0.6.2 firmware. I was able to receive a call and have a conversation once. After that I can call my phone and it will ring and show the gnome-calls app but I can't answer it. When I tap the button it shows the press but does nothing. The phone was on the lock screen when this happened.

When I log on to the phone and try to call it from another line, the phone does not show a call. I get log entries:

Apr 08 14:00:33 mobian ModemManager[1424]: transaction 0x12 aborted, but message is not abortable
Apr 08 14:00:33 mobian ModemManager[1424]: <warn>  [modem0/bearer1] reloading stats failed: QMI operation failed: Transaction timed out
Apr 08 14:00:42 mobian kernel: rk818-bat: changed: dsoc=36, rsoc=38, v=3602, ov=3790 c=-656, cap=1026, f=2708, st=charge off, hotdie=0
Apr 08 14:00:42 mobian kernel: rk818-bat: dl=41, rl=41, v=3679, halt=0, halt_n=0, max=0, init=0, sw=0, calib=0, below0=0, force=0
Apr 08 14:00:42 mobian upowerd[523]: energy_full (10.503432) is greater than energy_full_design (0.000000)
Apr 08 14:00:45 mobian ModemManager[1424]: transaction 0xc aborted, but message is not abortable
Apr 08 14:00:45 mobian ModemManager[1424]: <warn>  [modem0/call2] couldn't start call: QMI operation failed: Transaction timed out
Apr 08 14:00:52 mobian sudo[1755]: pam_unix(sudo:session): session closed for user root
Apr 08 14:00:54 mobian sudo[1798]:   mobian : TTY=pts/0 ; PWD=/home/mobian ; USER=root ; COMMAND=/usr/bin/journalctl -f
Apr 08 14:00:54 mobian sudo[1798]: pam_unix(sudo:session): session opened for user root(uid=0) by mobian(uid=1000)
Apr 08 14:01:03 mobian ModemManager[1424]: transaction 0x13 aborted, but message is not abortable
Apr 08 14:01:03 mobian ModemManager[1424]: <warn>  [modem0/bearer1] reloading stats failed: QMI operation failed: Transaction timed out
Apr 08 14:01:04 mobian eg25-manager[513]: Response: [RING]
Apr 08 14:01:04 mobian eg25-manager[513]: Executed soft sleep sequence
Apr 08 14:01:10 mobian kernel: usb 1-1: USB disconnect, device number 3
Apr 08 14:01:10 mobian kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Apr 08 14:01:10 mobian kernel: option 1-1:1.0: device disconnected
Apr 08 14:01:10 mobian kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Apr 08 14:01:10 mobian kernel: option 1-1:1.1: device disconnected
Apr 08 14:01:10 mobian kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Apr 08 14:01:10 mobian kernel: option 1-1:1.2: device disconnected
Apr 08 14:01:10 mobian kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
Apr 08 14:01:10 mobian kernel: option 1-1:1.3: device disconnected
Apr 08 14:01:10 mobian kernel: qmi_wwan 1-1:1.4 wwan0: unregister 'qmi_wwan' usb-fe3c0000.usb-1, WWAN/QMI device
Apr 08 14:01:10 mobian ModemManager[1424]: <info>  [base-manager] port ttyUSB0 released by device '/sys/devices/platform/fe3c0000.usb/usb1/1-1'
Apr 08 14:01:10 mobian ModemManager[1424]: <info>  [base-manager] port ttyUSB1 released by device '/sys/devices/platform/fe3c0000.usb/usb1/1-1'
Apr 08 14:01:10 mobian ModemManager[1424]: <info>  [base-manager] port ttyUSB2 released by device '/sys/devices/platform/fe3c0000.usb/usb1/1-1'
Apr 08 14:01:10 mobian systemd-networkd[1494]: wwan0: Link DOWN
Apr 08 14:01:10 mobian systemd-networkd[1494]: wwan0: Lost carrier
Apr 08 14:01:10 mobian ModemManager[1424]: Cannot read from istream: connection broken
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] QMI endpoint hangup: removed
Apr 08 14:01:10 mobian ModemManager[1424]: <info>  [modem0] connection to qmi-proxy for /dev/cdc-wdm0 lost, reprobing
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'wds' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'wds' client with ID '3'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'wds' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'wds' client with ID '2'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'voice' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'voice' client with ID '2'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'pdc' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'pdc' client with ID '1'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'loc' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'loc' client with ID '1'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'uim' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'uim' client with ID '1'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'wms' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'wms' client with ID '1'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'wds' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'wds' client with ID '1'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'nas' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'nas' client with ID '1'
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Releasing 'dms' client with flags 'release-cid'...
Apr 08 14:01:10 mobian ModemManager[1424]: [/dev/cdc-wdm0] Unregistered 'dms' client with ID '1'
Apr 08 14:01:10 mobian ModemManager[1424]: <info>  [base-manager] port cdc-wdm0 released by device '/sys/devices/platform/fe3c0000.usb/usb1/1-1'
Apr 08 14:01:10 mobian ModemManager[1424]: <info>  [base-manager] port ttyUSB3 released by device '/sys/devices/platform/fe3c0000.usb/usb1/1-1'
Apr 08 14:01:10 mobian NetworkManager[1544]: <info>  [1649440870.8102] device (cdc-wdm0): state change: activated -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Apr 08 14:01:10 mobian eg25-manager[513]: ModemManager object `/org/freedesktop/ModemManager1/Modem/0' removed
Apr 08 14:01:10 mobian ModemManager[1424]: <info>  [base-manager] port wwan0 released by device '/sys/devices/platform/fe3c0000.usb/usb1/1-1'
Apr 08 14:01:10 mobian mmsdtng[663]: ../plugins/modemmanager.c:mmsd_modem_unavailable() Disabling Bearer Handler
Apr 08 14:01:10 mobian mmsdtng[663]: ../src/service.c:mms_service_set_bearer_handler() service 0xaaaadd056290 handler (nil)
Apr 08 14:01:10 mobian mmsdtng[663]: ../plugins/modemmanager.c:mmsd_disconnect_from_sms_wap() Stopping watching SMS WAPs
Apr 08 14:01:10 mobian mmsdtng[663]: ../plugins/modemmanager.c:mmsd_mm_state() Modem vanished, Disabling plugin
Apr 08 14:01:10 mobian mmsdtng[663]: ../plugins/modemmanager.c:mmsd_mm_state() MMSD_MM_STATE_NO_MODEM
Apr 08 14:01:10 mobian mmsdtng[663]: ../plugins/modemmanager.c:cb_object_removed() Modem removed: /org/freedesktop/ModemManager1/Modem/0
Apr 08 14:01:10 mobian dbus-daemon[510]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.69' (uid=0 pid=1544 comm="/usr/sbin/NetworkManager --no-daemon")
Apr 08 14:01:10 mobian systemd[1]: Starting Network Manager Script Dispatcher Service...
Apr 08 14:01:10 mobian NetworkManager[1544]: <warn>  [1649440870.8731] modem-broadband[cdc-wdm0]: failed to disconnect modem: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: Object does not exist at path “/org/freedesktop/ModemManager1/Modem/0”
Apr 08 14:01:10 mobian NetworkManager[1544]: <warn>  [1649440870.8776] dns-sd-resolved[18e7b0313af67001]: send-updates SetLinkDomains@4 failed: GDBus.Error:org.freedesktop.resolve1.NoSuchLink: Link 4 not known
Apr 08 14:01:10 mobian dbus-daemon[510]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 08 14:01:10 mobian systemd[1]: Started Network Manager Script Dispatcher Service.
Apr 08 14:01:11 mobian kernel: usb 1-1: new high-speed USB device number 4 using ehci-platform
Apr 08 14:01:11 mobian kernel: usb 1-1: New USB device found, idVendor=2c7c, idProduct=0125, bcdDevice= 0.00
Apr 08 14:01:11 mobian kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Apr 08 14:01:11 mobian kernel: usb 1-1: Product: EG25-G
Apr 08 14:01:11 mobian kernel: usb 1-1: Manufacturer: Quectel
Apr 08 14:01:11 mobian kernel: option 1-1:1.0: GSM modem (1-port) converter detected
Apr 08 14:01:11 mobian kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
Apr 08 14:01:11 mobian systemd-udevd[1804]: 1-1: /usr/lib/udev/rules.d/80-modem-eg25.rules:3 Failed to write ATTR{/sys/devices/platform/fe3c0000.usb/usb1/1-1/power/wakeup}, ignoring: No such file or directory
Apr 08 14:01:16 mobian PackageKit[1197]: get-updates transaction /2491_bcdeaeca from uid 1000 finished with success after 1235ms
Apr 08 14:01:16 mobian PackageKit[1197]: get-details transaction /2492_bbedeeea from uid 1000 finished with success after 696ms
Apr 08 14:01:19 mobian ModemManager[1424]: <info>  [device /sys/devices/platform/fe3c0000.usb/usb1/1-1] creating modem with plugin 'quectel' and '1' ports
Apr 08 14:01:19 mobian ModemManager[1424]: <warn>  [plugin/quectel] could not grab port ttyUSB0: Cannot add port 'tty/ttyUSB0', unhandled port type
Apr 08 14:01:19 mobian ModemManager[1424]: <warn>  [base-manager] couldn't create modem for device '/sys/devices/platform/fe3c0000.usb/usb1/1-1': Failed to find primary AT port
Apr 08 14:01:21 mobian systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Apr 08 14:02:10 mobian kernel: panel-himax-hx8394 ff960000.mipi.0: disable
Apr 08 14:02:10 mobian kernel: dw-mipi-dsi-rockchip ff960000.mipi: disable
Apr 08 14:02:10 mobian kernel: dw-mipi-dsi-rockchip ff960000.mipi: post disable
Apr 08 14:02:10 mobian kernel: dw-mipi-dsi-rockchip ff960000.mipi: mode 0
Apr 08 14:02:10 mobian kernel: panel-himax-hx8394 ff960000.mipi.0: unprepare

Interestingly I get this log entry and then the modem disappears and I have to power off the phone and power it back on to get the modem back:

mobian systemd-udevd[1804]: 1-1: /usr/lib/udev/rules.d/80-modem-eg25.rules:3 Failed to write ATTR{/sys/devices/platform/fe3c0000.usb/usb1/1-1/power/wakeup}, ignoring: No such file or directory

I tried to run the log collector script when the modem was missing and got this:

* daemon not running; starting now at tcp:5037
* daemon started successfully
error: no devices/emulators found
error: no devices/emulators found
adb: error: failed to get feature set: no devices/emulators found

I guess that's not a surprise since the modem isn't responding and likely is in a failed state.

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Apr 8, 2022 via email

@InfiniteOtter
Copy link
Author

Having reverted to 6.1 I did some testing to try and isolate issues.

When using a bluetooth headphone there is no connection at all to the phone and the sound reverts to the internal mic and speakers.
When recording with the bluetooth headphone, the clicking like telegraph operators are trying to sync with my speech still happens and mic volume diminished sound and clicking equally. So that part of the static is probably not part of the modem.

When i use the internal mic to record, I have the same sort of sound that the bluetooth headphone gives, so the problem is not with the microphone or it's specific circuitry.

When I make a call, on the Pinephone Pro the sound for me is clear and quite good. No complaints at all for the Pinephone end of the conversation.
The phone I called or who called my Pine phone however gets horrible reception. I can barely make out speech and there is loud background noise like the sort of sounds you might here in a movies sound effects for computer and phone noises. Not all just static.

@CodePhase
Copy link
Contributor

CodePhase commented Apr 8, 2022 •
edited
Loading

I had that same problem running on Mobian Phosh (bookworm). I was able to work around it by setting the microphone (input) volume all the way down to as low as it would go without being mute in Settings->Sounds and also setting the IN1 boost to '0' in /usr/share/alsa/ucm2/PinePhonePro/VoiceCall.conf

I'll also note that while this greatly improves the other side's audio, there is still a short delay and echo that occurs on their end i.e. they can still hear what they said a second after they've said it.

@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 9, 2022

@CodePhase It seems I was right to put the statement in there, the modem crashed (I had quite a few things half cooked there, but we needed to know if setting the alsa controls again would fix the sound issue), so release was a mess, but fix does work :P
Going to pull it from the releases now to avoid confusion but the fix stays for next release.

Just one little thing before you wipe that firmware off from the phone. When you couldn't answer or hang up is probably because openqti crashed and was restarting (before everything went to hell... If you could try that again and dump a kernel+openqti log before it reboots it would help me pinpoint where it crashed

@CodePhase
Copy link
Contributor

CodePhase commented Apr 9, 2022 •
edited by Biktorgj
Loading

@Biktorgj I'm glad you may have an idea what's going on! I did another test as you asked. Here's what I did:

  • Powered off and powered on Pinephone
  • Called Pinephone from landline. Pinephone did not react at all (did not show a call)
  • Restarted ModemManager service
  • Called Time service from Pinephone (successful)
  • Called Pinephone from landline. This time Calls came up but again I couldn't answer the call when I tapped the answer button

I've attached the logs:
dmesg-modem.txt
dmesg-pinephone.txt
eg25-manager.log
modemmanager.log
networkmanager.log

I hope this helps!

@Biktorgj
Copy link
Collaborator

Biktorgj commented Apr 9, 2022

There's some Interesting stuff in your logs

(From modem's dmesg):

[   24.497610] random: nonblocking pool is initialized
[   40.518480] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[   59.170130] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
[   62.928679] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[   65.800522] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_REMOTE_WAKEUP_EVENT received
[   65.855227] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
[   69.662014] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[   71.800872] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_REMOTE_WAKEUP_EVENT received
[   71.855113] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
[   75.655992] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[   77.801309] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_REMOTE_WAKEUP_EVENT received
[   77.856188] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
[   92.895707] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[   94.259587] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
[  119.130634] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[  124.547343] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
[  137.160611] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[  140.198764] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
[  147.217683] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[  152.430452] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received

At 24 second mark ModemManager was ready, but then there's a lot of requests from the Pinephone to suspend the modem, until this happens:

[  152.783427] msm_thermal:do_freq_control Limiting CPU0 max frequency to 1094400. Temp:60
[  153.033428] msm_thermal:do_freq_control Limiting CPU0 max frequency to 800000. Temp:60
[  153.283422] msm_thermal:do_freq_control Limiting CPU0 max frequency to 200000. Temp:60
[  153.533402] msm_thermal:do_freq_control Limiting CPU0 max frequency to 110000. Temp:60

So the modem was heating up. It wasn't doing anything so there should be no reason for that, I assume the Pinephone was doing something a bit more intensive thus heating the board a bit (modem can stand up to 85ºC before powering itself off, so nothing to worry about). But then this happened:

[  153.942948] mdm_auxpcm_mode_put: mdm_auxpcm_mode = 1 ucontrol->value = 0
[  153.945301] mdm_sec_auxpcm_mode_put: mdm_sec_auxpcm_mode = 1 ucontrol->value = 0
[  156.224569] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
[  156.308415] mdm_auxpcm_mode_put: mdm_auxpcm_mode = 1 ucontrol->value = 0
[  156.312527] mdm_sec_auxpcm_mode_put: mdm_sec_auxpcm_mode = 1 ucontrol->value = 0
[  157.517162] afe_open: port_id 0x100c rate 16000
[  157.523037] afe_open: port_id 0x100d rate 16000

That first message indicates the sound driver is getting ready to be powered on. As the call was getting prepared the Pinephone tried to suspend the modem's USB port again (156 second mark). Here's where modemmanager crapped out and tried to reregister to the modem, hence making you loose that call. As the USB port was suspended, the messages between ModemManager and the Modem were not going through, and by the time usb was resumed, modemmanager had already given up (Modem tried to wake up the Pinephone's usb port 5 seconds later -[ 158.033426] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_REMOTE_WAKEUP_EVENT received-)

So, as another test, can you disable autosuspend in the USB port? Maybe something has changed in the Pinephone Pro's kernel lately that makes it more aggressive when trying to suspend the port

You'd need to change the following line from this:
ACTION=="add", SUBSYSTEM=="usb", DRIVERS=="usb", ENV{DEVTYPE}=="usb_device", ATTRS{idVendor}=="2c7c", ATTRS{idProduct}=="0125", ATTR{power/control}="auto"

To this:
ACTION=="add", SUBSYSTEM=="usb", DRIVERS=="usb", ENV{DEVTYPE}=="usb_device", ATTRS{idVendor}=="2c7c", ATTRS{idProduct}=="0125", ATTR{power/control}="on"

In /usr/lib/udev/rules.d/80-modem-eg25.rules

The modem userspace didn't crash, but I think it's starting to query some network details too fast, and that might also be interfering with eg25-manager and ModemManager when they haven't really finished querying the modem or uploading AGPS data, so I've disabled reading AT+CIND in an alternate build you can get here:
https://github.com/Biktorgj/pinephone_modem_sdk/releases/latest

Pick the file named package-alt.tar.gz

From the timings it looks like you have the PIN code disabled?

@CodePhase
Copy link
Contributor

Well, I hate to say it but I might know why those logs show odd power issues. I was experimenting with the new Mobian Phosh installer with full disk encryption and put in a new SD card with a new install. I thought I restored everything as my first install but I forgot about the settings in /usr/lib/udev/rules.d/80-modem-eg25.rules, including the persistance value. That's the bad news; I hope I didn't waste your time @Biktorgj.

The good news is that I spent the day productively and have some new logs for you. I made the changes to the udev file, including the power control you mentioned, and ran the same test on both 0.6.2 (original) and 0.6.2-alt. Here's the sequence I used:
0.6.2 Original:

  • Powered off and then powered on Pinephone
  • lock screen: called Pinephone from landline, no reaction
  • logged in, called modem loopback, successful
  • called time service, no connection
  • restarted ModemManager
  • called Pinephone from landline, rang but couldn't answer
    -- after log collect --
  • called time service, couldn't connect (not captured in logs)

0.6.2-alt:

  • Powered off and then powered on Pinephone
  • lock screen: called Pinephone from landline, no reaction
  • logged in, called modem loopback, successful
  • called time service, no connection
  • restarted ModemManager
  • called Pinephone from landline, rang but couldn't answer
  • called time service, couldn't connect
  • restarted modem
  • restarted modemmanager
  • called Pinephone from landline, rang but couldnt answer
  • called time service, no connection

Also, I wanted to let you know that I spent a bunch of time today creating a log file personal information scrubber. Since I've been submitting a bunch of logs here I figured it will save me and hopefully other users here some time in the long run. Checkout out my pull request #83

6_2-dmesg-modem.txt
6_2-dmesg-pinephone.txt
6_2-eg25-manager.log
6_2-modemmanager.log
6_2-networkmanager.log
6_2-openqti.log
6_2_alt-dmesg-modem.txt
6_2_alt-dmesg-pinephone.txt
6_2_alt-eg25-manager.log
6_2_alt-modemmanager.log
6_2_alt-networkmanager.log
6_2_alt-openqti.log

@Biktorgj
Copy link
Collaborator

Thanks for the scrubber! Would it make sense to incorporate it in the collect logs script so it's done automatcially?
Made a new release with a lot of changes. I think what you were hitting was a buffer underrun, but not entirely sure.

Please give it a shot and let me know if it's more stable (haven't been able to reproduce the bug myself): https://github.com/Biktorgj/pinephone_modem_sdk/releases/tag/0.6.3

@CodePhase
Copy link
Contributor

Glad I could help with the scrubber! Makes my life easier too. Your wish is my command for incorporating into the log collector: #84.

Thank you so much for all the work you've been doing and so quickly! I installed 0.6.3 and did the same test with these results:

  • Powered off and then powered on Pinephone
  • lock screen: called Pinephone from landline, no reaction
  • logged in, called modem loopback, successful
  • called time service, no connection
  • restarted ModemManager
  • called Pinephone from landline, success!
  • called time service, success!
  • sent test sms, success!

Overall, an improvement! I have not tested calling after suspend or suspend for long periods (> 1 hr). I'll give that a shot and let you know if anything changes. Thank you again!

dmesg-modem.txt
dmesg-pinephone.txt
eg25-manager.log
modemmanager.log
networkmanager.log
openqti.log

@CodePhase
Copy link
Contributor

To follow up, calling my Pinephone Pro from a landline while it's been suspended, even after time more than an hour works! I can answer the call and the speaker / mic function. I wonder if the issue of not being able to have working calls after bootup is a ModemManager issue.

I also wonder if maybe I have some different settings than you @Biktorgj and that's why you can't reproduce the issue. I'll have to double-check my configuration with the Mobian wiki and tips / tricks.

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Apr 11, 2022 •
edited
Loading

Congratulations, Biktorgj! 6.3 is a huge step forward.
I called my wife to test. We swapped phones during the test. On the PPP no issues at all! Sound is great and the connection is great!
On the MotoG6, the sound when the PPP user talks is great!

When the user talks though, the echo, and static is however horrible. The feed back from the PPP when the other user is talking, is horrible for the other user. Using the PPP, I don't hear any problems when the other user talks. On the MotoG6 it's a horrible experience and hard to focus on talking.

With 6.3 my wife and I can use it to talk, but I would not win any friends if I used it to call strangers.
This is huge progress in a short time! Again, Congratulations!

@CodePhase
Copy link
Contributor

CodePhase commented Apr 11, 2022 •
edited
Loading

@InfiniteOtter, did you try setting the IN1 Boost to '0' and reducing the microphone volume in Settings->Sound? People I talk to still get an echo but it's nowhere near as bad with those two changes.

@carlosgonz0
Copy link

carlosgonz0 commented Apr 11, 2022 •
edited
Loading

Calls still broke on Sailfish OS and Firmodem 0.6.3 like: not sound not mic. PP - PPP

@InfiniteOtter
Copy link
Author

Sorry about the delay in replying I had a Sandisk Extreme 128gb microSD die on me so I had to start over. I went ahead and loaded tow-boot since all the cool kids are using it. Took me a while to get everything back up to date.

Echo isn't as bad with the IN1 Boost down. Still feels like you are at the bottom of the well with odd underwater sounds and digital effects in the background.

@Biktorgj
Copy link
Collaborator

@CodePhase The first call doesn't even show up in openqti's log... did it give you a tone from the landline at all?
@carlosgonz0 That certainly looks like some bug in Sailfish OS, not sure I can do much about it

For everyone with a Pinephone Pro:
Here's a test kernel, with a small tweak to input volume in the analog audio codec. This reduces the microphone input level, and in my limited testing it reduced the background noise during calls.
Please, revert any changes to ALSA config (IN boost, specifically) and give it a try!
SHA512SUM of the kernel: 3f8f8c3cb52cb30d5cc018d809f45ef278545dd96632c23821b7a9fabff2d23a9e2d6def91885cee7a9e848eb041e18e603f5ee6231790f922fc3c485a7ff9cc mdm9607-perf-boot.img
mdm9607-test-volume.tar.gz

To flash it:

  1. Get to fastboot (echo -ne "AT+QFASTBOOT\r" /dev/ttyUSB2
  2. fastboot flash boot mdm9607-perf-boot.img
  3. fastboot reboot

@SpookySkeletons
Copy link

Lovely, just tested. Much less noise and my voice doesnt clip nearly as bad!
Still room for improvement but this is nice.

@CodePhase
Copy link
Contributor

@Biktorgj to answer your question, yes I let the landline side ring for 15 seconds. Now that you mention it however, my voicemail did not pick up so that's an interesting twist. Maybe it was a failure on the carrier side.

I just installed the test volume kernel and will give you some feedback!

This was referenced Apr 16, 2022
Closed
Closed
@InfiniteOtter
Copy link
Author

With 6.7, we have a viable and usable phone in the Mobian environment. Still a hint of echo for the remote user, but the initial issue listed here is quite well solved. On Manjaro, there is still noise in the background but since it is fine in Mobian, we can't really blame the SDK.
Brilliant work Biktorgj, thank you for making the PPP a working phone. :)

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Oct 11, 2022 via email

@Biktorgj
Copy link
Collaborator

First step to get logs from the modem would be to enable ADB. You can do that with an AT command (AT+ADBON) (as root, echo -ne 'AT+ADBON\n\r' > /dev/ttyUSB2, or sending enable adb in the chat (note the number changed quite a few versions ago and it's now +223344556677)

Once enabled, you can pull the logs from the modem like this:
adb pull /var/log/openqti.log
adb shell dmesg > modem_kernel.log

Or, if you enable persistent storage for openqti (so the modem keeps last 30 app logs in flash)
adb pull /persist/openqti.log

@InfiniteOtter
Copy link
Author

InfiniteOtter commented Oct 11, 2022 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@Biktorgj @CodePhase @InfiniteOtter @SpookySkeletons @carlosgonz0