When trying to use a https printer i get socket timeout.

[dlux95]

I already posted on google play that i cannot connect to a printer with https and authentication. When doing so it results in socket timeout.

[BenoitDuffez]

Does it work from other clients?

I have an USB printer on a raspberry, and I have tested with and without HTTPS (self signed certificate), with and without http basic auth, and all 4 cases worked fine with the app.

I haven't tested these recently, but currently my setup is over https without authentication and it works perfectly.

Can you please confirm this works from another device such smash a computer? If it works, please collect the Android logs and share them here.

Thanks

[dlux95]

It does indeed work on other devices, i tried two linux systems and even one windows system and they both work fine.

Perhaps the issue is occuring because the connection is over the Internet and not local. Another reason might be the haproxy instance that is between the router and the cups print server. Maybe this app is trying to get information about the printer which is not possible in the haproxy setupt (I only forward /printers/Printer_1 to cups). Will gather a log file now.

[dlux95]

09-11 00:06:20.334 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:21.196 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:21.245 14963-15630/? I/chatty: uid=10117(io.github.benoitduffez.cupsprint) AsyncTask #5 identical 5 lines 09-11 00:06:21.334 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:22.229 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:22.389 14963-15630/? I/chatty: uid=10117(io.github.benoitduffez.cupsprint) AsyncTask #5 identical 4 lines 09-11 00:06:22.522 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:23.390 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:23.526 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:24.246 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:24.246 14963-15630/? I/chatty: uid=10117(io.github.benoitduffez.cupsprint) AsyncTask #5 identical 1 line 09-11 00:06:24.248 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:24.256 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:24.390 14963-15630/? I/chatty: uid=10117(io.github.benoitduffez.cupsprint) AsyncTask #5 identical 3 lines 09-11 00:06:24.526 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@4ad8b07 09-11 00:06:25.571 14963-15630/? V/CUPS: No answer in mDNS response: java.net.DatagramPacket@d1a525d 09-11 00:06:26.626 14963-14963/? D/CUPS: onPrintersDiscovered({https://domain:443/printers/6_Warteschlange=Ratse Warteschlange}) 09-11 00:06:35.692 14963-14963/? D/CUPS: onStartPrinterStateTracking: PrinterId{serviceName=io.github.benoitduffez.cupsprint/io.github.benoitduffez.cupsprint.printservice.CupsService, localId=https://domain:443/printers/6_Warteschlange} 09-11 00:06:35.693 14963-15613/? I/CUPS: Checking printer status: PrinterId{serviceName=io.github.benoitduffez.cupsprint/io.github.benoitduffez.cupsprint.printservice.CupsService, localId=https://domain:443/printers/6_Warteschlange} 09-11 00:06:35.698 14963-15613/? E/CUPS: Couldn't open local key store: /data/user/0/io.github.benoitduffez.cupsprint/files/cupsprint-trustfile (No such file or directory) 09-11 00:06:36.652 14963-15613/? E/CUPS: Caught exception while connecting to printer https://domain:443/printers/: https://domain:443/printers/ 09-11 00:06:36.655 14963-14963/? V/CUPS: HTTP response code: 411

[BenoitDuffez]

Hm I don't know on top of my head what URLs are attempted when connecting to the printer. I know there is an mDNS scan which triggers the logs we see ("No answer..." blah blah) which is normal.

Then the server replies with HTTP 411 which I had never seen before. The Content-Length header is managed by the HttpURLConnection API which is currently set to chunked mode.

I have generated a signed APK with the only change to fixed length instead of chunked. Please let me know if the log in Android changes (don't forget to anonymize it before you upload it). Since it is signed you should be able to install it over the one you already have without any risk (provided you installed from the Play Store in the first place).

I don't know if this would change anything... I haven't even tested it myself. Let me know.

Download apk: https://upactivity.com/cupsprint_bug111.apk

diff --git a/app/src/main/java/org/cups4j/operations/IppOperation.kt b/app/src/main/java/org/cups4j/operations/IppOperation.kt
index 9002325..d02bd3d 100644
--- a/app/src/main/java/org/cups4j/operations/IppOperation.kt
+++ b/app/src/main/java/org/cups4j/operations/IppOperation.kt
@@ -128,7 +128,7 @@ abstract class IppOperation(val context: Context) {
             connection.connectTimeout = 10000
             connection.doInput = true
             connection.doOutput = true
-            connection.setChunkedStreamingMode(0)
+            connection.setFixedLengthStreamingMode(ippBuf.limit())
             connection.setRequestProperty("Content-Type", IPP_MIME_TYPE)
 
             if (url.protocol == "https") {

[dlux95]

I think returning 411 is resolved now. But there is another Exception down the line.

09-12 11:23:43.252 24985-24985/? D/null: onStartPrinterStateTracking: PrinterId{serviceName=io.github.benoitduffez.cupsprint/io.github.benoitduffez.cupsprint.printservice.CupsService, localId=https://domain.de:443/printers/6_Warteschlange}
09-12 11:23:43.253 24985-26709/? I/null: Checking printer status: PrinterId{serviceName=io.github.benoitduffez.cupsprint/io.github.benoitduffez.cupsprint.printservice.CupsService, localId=https://domain:443/printers/6_Warteschlange}
09-12 11:23:43.254 24985-26709/? E/null: Couldn't open local key store: /data/user/0/io.github.benoitduffez.cupsprint/files/cupsprint-trustfile (No such file or directory)
09-12 11:23:43.933 24985-26709/? E/null: Couldn't open local key store: /data/user/0/io.github.benoitduffez.cupsprint/files/cupsprint-trustfile (No such file or directory)
09-12 11:23:44.078 24985-26709/? E/null: Couldn't open local key store: /data/user/0/io.github.benoitduffez.cupsprint/files/cupsprint-trustfile (No such file or directory)
09-12 11:23:44.336 24985-24985/? E/null: Start printer state tracking failed
    java.io.FileNotFoundException: https://domain:443/printers/6_Warteschlange
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getInputStream(HttpURLConnectionImpl.java:251)
        at com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getInputStream(DelegatingHttpsURLConnection.java:210)
        at com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getInputStream(Unknown Source:0)
        at org.cups4j.operations.IppOperation.sendRequest(IppOperation.kt:156)
        at org.cups4j.operations.IppOperation.sendRequest$default(IppOperation.kt:120)
        at org.cups4j.operations.IppOperation.request(IppOperation.kt:66)
        at io.github.benoitduffez.cupsprint.printservice.CupsPrinterDiscoverySession.checkPrinter(CupsPrinterDiscoverySession.kt:145)
        at io.github.benoitduffez.cupsprint.printservice.CupsPrinterDiscoverySession$onStartPrinterStateTracking$1.run(CupsPrinterDiscoverySession.kt:369)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:764)

You documented that the FileNotFound Exception is raised for every 4XX status code. Perhaps basic auth is not working for checkprinter()?

Edit: The 411 might be a special case for our setup. I don't want to risk compatability with other setups so a configuration option for that case would be ideal.

[BenoitDuffez]

the "Start printer state tracking failed" message is printed only if handlePrinterException returns true, which does only if handleHttpError returns true, which happens only if the HTTP status code is none of: HTTP_NOT_FOUND, HTTP_BAD_REQUEST, HTTP_UNAUTHORIZED, or HTTP_UPGRADE_REQUIRED.

So that is not related to basic auth.

Also, the only way to have this trace is when this line is reached:

Toast.makeText(printService, exception.localizedMessage, Toast.LENGTH_LONG).show()

So you should have seen the error message on the bottom of the screen. Am I right?

[dlux95]

No there is no Error Message at the bottom. Nothing except that the printing dialogue says that the printer is currently not available like before. And the only Toast i received after selecting the printer is with the printers URL which is correct.

[dlux95]

But it never asked for username and password which are required for accessing the printer

[BenoitDuffez]

I'd have to enable basic auth again on my setup and test this before I can help you more. I'll update this issue when I have more information.

[dlux95]

When you explain the procedure / steps involved in the process i can experiment a bit on my own.

[BenoitDuffez]

It seems I have received a FileNotFoundException report, from you (***.de). So my assumptions in this post where wrong.

This exception is raised IIRC when there is a basic auth required (weird huh? why not explicit authentication required exception? I don't know). So there might be a bug or a regression that I need to work on. I'll have to enable authentication on my CUPS server, then run the app with the debugger and see line by line which exception is raised and how it should be handled.

You could do it if you know how to. Otherwise I'll do it when I find some time.

[dlux95]

I meant the general procedure of how this app works (entrypoints from android, order in which functions should be run and so on) and not how bug tracking works in general.

I study CS so there might be a chance that i find it out by myself. While i have time to track down the bug and experience with Java i have no clue about how printing works on Android devices.

If you could explain that a bit and how this app works then i can search for it.

[BenoitDuffez]

I migrated the code to Kotlin but that shouldn't be too difficult from a Java developer.

Basically Android manages printing itself. It receives print jobs from the user, presents a list of printers, and send the print jobs to the application managing the printing.

So the entry points are:

• listing the printers
• sending jobs to the printer
• showing job updates / job operations (cancel, pause, etc)

The listing of printers is launched during a discovery session. Enter CupsPrinterDiscoverySession.kt.

The job management is managed by the CupsService.

Then for the structure:

• io.github.benoitduffez.cupsprint.detect manages mDNS scan and conversion from UDP datagrams to printers lists
• io.github.benoitduffez.cupsprint.ssl manages the custom SSL handling: when a self signed certificate is used, it can be stored on the device memor
• io.github.benoitduffez.cupsprint.app contains all the UI related code
• ch/ethz/vppserver contains an IPP client
• org/cups4j contains the CUPS client

You just need Android Studio.

[dlux95]

I will see if i can find the issue then. If there is an issue i will post it here.

[dlux95]

After staticly inserting username and password to HttpConnectionManagement.kt Android offers me to start the print job (query for printer capabilities seems to be working). But when i hit the print button it suddenly fails to do so with following message:

09-13 23:56:25.061 9966-9966/io.github.benoitduffez.cupsprint E/CupsService: Couldn't query job android.print.PrintJobId@b86e5ed2
    kotlin.UninitializedPropertyAccessException: lateinit property jobName has not been initialized
        at org.cups4j.PrintJob$Builder.getJobName(PrintJob.kt:67)
        at org.cups4j.PrintJob.<init>(PrintJob.kt:38)
        at org.cups4j.PrintJob$Builder.build(PrintJob.kt:162)
        at io.github.benoitduffez.cupsprint.printservice.CupsService.printDocument$app_debug(CupsService.kt:288)
        at io.github.benoitduffez.cupsprint.printservice.CupsService$onPrintJobQueued$1.run(CupsService.kt:133)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:764)

I think the reason why it is not working with Auth is the assumption that credentials are only required for printing the document. The dialogue where i can put in credentials didn't show up in the first place thus HttpConnectionManagement.kt cant insert Http Auth credentials into headers. If Credentials are only required for printing then the dialogue will show up when trying to print (which is not offered when capability checks fail which wont work with auth) at least thats my assumption.

[dlux95]

Next issue: When i staticly define the jobName the print won't start because the url of the printer changes in the system because CupsClient.kt tries to guess the printer by given URL and PrinterList from Cups:

fun getPrinter(printerURL: URL): CupsPrinter? {
        val printers = printers
        for (p in printers) {
            if (p.printerURL.path == printerURL.path)
                return p
        }
        return null
    }

When defining a static printer and use it all the time printing won't start because of an issue that might be related with disabling Chunked Transfer type:

09-14 00:26:53.925 13996-13996/io.github.benoitduffez.cupsprint E/CupsService: Couldn't query job android.print.PrintJobId@ae60910b
    java.net.ProtocolException: expected 216 bytes but received 8408
        at com.android.okhttp.internal.http.Http1xStream$FixedLengthSink.write(Http1xStream.java:285)
        at com.android.okhttp.okio.RealBufferedSink.emit(RealBufferedSink.java:183)
        at com.android.okhttp.internal.http.HttpEngine.readResponse(HttpEngine.java:581)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:471)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:407)
        at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:538)
        at com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getResponseCode(DelegatingHttpsURLConnection.java:105)
        at com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getResponseCode(Unknown Source:0)
        at org.cups4j.operations.IppOperation.sendRequest(IppOperation.kt:164)
        at org.cups4j.operations.IppOperation.request(IppOperation.kt:69)
        at org.cups4j.CupsPrinter.print(CupsPrinter.kt:124)
        at io.github.benoitduffez.cupsprint.printservice.CupsService.printDocument$app_debug(CupsService.kt:289)
        at io.github.benoitduffez.cupsprint.printservice.CupsService$onPrintJobQueued$1.run(CupsService.kt:133)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:764)

[dlux95]

Removing connection.setFixedLengthStreamingMode(ippBuf.limit()) from your test apk and the chunked thing from the current source then printing finally works (i get a bunch of error messages telling me that the print job does not exist , is it finished? but that might be related to that the print job is processed immediatly by a script and not in the printer queue anymore).

I try to clean up some parts of the code and make pull requests for them.

[BenoitDuffez]

Awesome!

[dlux95]

My assumption about auth was a bit wrong but the results are the same. Testing wether a cert or auth is required is done in these lines:

 val client = CupsClient(printService, clientURL).setPath(path ?: "/")
        val testPrinter: CupsPrinter?

        // Check if we need to save the server certs if we don't trust the connection
        try {
            testPrinter = client.getPrinter(printerURL)

But the root of the url is not protected by a http auth, meaning that this request will not fail. If there is an auth on URL root than some of the catch blocks will put the correct response code in the required field in order for the outer handlePrinterError or handleHttpError to handle the Authentication error. But because auth is required only for the printer the request will only fail here: val ippAttributes = op.request(printerURL, propertyMap) meaning that responseCode is not set properly -> no auth dialogue.

fixing that issue would mean a large rewrite of that portion.

[BenoitDuffez]

I have received a crash report in #112 with the exact same error, and with a printer I believe is one of yours (https://print.rats*******:443/printers/6_Warteschlange).

Can you tell me, if this is your printer, if the URL mentioned is actually legit?

The exception is raised by CupsPrinterDiscoverySession:380:

else -> Timber.e(e, "Start printer state tracking failed")

This follows a failed call of checkPrinter(printerId.localId, printerId) in onStartPrinterStateTracking. The printerId contains the URL, it is provided by Android. I think this comes from the discovery phase.

The discovery phase triggers a call to CupsPrinterDiscoverySession.scanPrinters. This sends an mDNS scan, but also adds all the manually entered printers. Can you tell me whether the printer above is manual or mDNS?

For now I will assume this is mDNS (because manual would mean user error, not app error).

The URL is built as rec.protocol + "://" + rec.host + ":" + rec.port + "/printers/" + rec.queue, rec being a PrinterRec built from the mDNS scan.

The mDNS scan is performed in MdnsServices and the printer is actually added on line 140. The printer rec is created:

getPrinterRec(
        info.name,
        protocol, // protocol
        services[key]!![0], // host
        Integer.parseInt(services[key]!![1]), // port
        rp) // queue

So the URL is basically built from the mDNS response.

The bottom line of this is I think this comes from a misconfigured mDNS daemon, or a misconfigured CUPS server. Or an edge case not covered by this app.

Since I can't reproduce it's really hard for me to help. I hope my analysis helps a bit.

[BenoitDuffez]

Upon re-reading your inputs:

But the root of the url is not protected by a http auth, meaning that this request will not fail. If there is an auth on URL root than some of the catch blocks will put the correct response code in the required field in order for the outer handlePrinterError or handleHttpError to handle the Authentication error. But because auth is required only for the printer the request will only fail here: val ippAttributes = op.request(printerURL, propertyMap) meaning that responseCode is not set properly -> no auth dialogue.

fixing that issue would mean a large rewrite of that portion.

I see that you don't use basic auth on / but on other URLs. Please post your cupsd.conf file so that I can reproduce the issue. Maybe the authentication dialog is triggered only if a 401 is returned from certain URLs but not all.

If that's the case, I don't believe there would be a large rewrite. I'm waiting for your feedback on this.

[dlux95]

For now I will assume this is mDNS (because manual would mean user error, not app error).

It is not but the printer url is the right one. One of the problem is that the manual entered printer url is not used for the real printing part of the app. There CupsClient.getPrinter is called. In this method only the path of the printer url is checked against the list so the port gets overwritten and the app tries to connect on a different port than entered manually.

Posting my cupsd.conf wouldn't help that much because the only url that is handled by cups is the /printers/6_Warteschlange part. All other requests are routed to another webserver by a proxy that sits in front of our cups server.

[BenoitDuffez]

Please see my comments on #114. I believe that this PR would fix this issue.

[dlux95]

thats why i posted that PR 😄

[BenoitDuffez]

Yes but have you seen my review on it? I posted it earlier tonight.

[dlux95]

what review?

[BenoitDuffez]

https://github.com/BenoitDuffez/AndroidCupsPrint/pull/114#pullrequestreview-157446008

[dlux95]

i only see a post from you two days ago on #114

[BenoitDuffez]

[BenoitDuffez]

PR was merged & published as 1.5.0 on the play store. Please tell me whether this is fixed and we can close this. Thanks

[BenoitDuffez]

Hi @laubed, can we close this?